[==========] 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:26.713411 32212 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.31.117.62:33801
I20260812 06:18:26.714450 32212 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:26.715076 32212 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:26.721730 32223 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:26.721768 32224 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:26.721887 32212 server_base.cc:1061] running on GCE node
W20260812 06:18:26.722110 32226 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:26.722615 32212 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:26.722728 32212 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:26.722771 32212 hybrid_clock.cc:648] HybridClock initialized: now 1786515506722769 us; error 0 us; skew 500 ppm
I20260812 06:18:26.724424 32212 webserver.cc:533] Webserver started at http://127.31.117.62:45851/ using document root <none> and password file <none>
I20260812 06:18:26.724984 32212 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:26.725065 32212 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:26.725302 32212 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:26.726998 32212 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515506702625-32212-0/minicluster-data/master-0-root/instance:
uuid: "2b4bde84d11e40dfac5cc6bcfa255c4a"
format_stamp: "Formatted at 2026-08-12 06:18:26 on dist-test-slave-gkw7"
I20260812 06:18:26.730432 32212 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.001s	sys 0.003s
I20260812 06:18:26.732417 32232 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:26.733566 32212 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.001s
I20260812 06:18:26.733692 32212 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515506702625-32212-0/minicluster-data/master-0-root
uuid: "2b4bde84d11e40dfac5cc6bcfa255c4a"
format_stamp: "Formatted at 2026-08-12 06:18:26 on dist-test-slave-gkw7"
I20260812 06:18:26.733803 32212 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515506702625-32212-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515506702625-32212-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515506702625-32212-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:26.777408 32212 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:26.778164 32212 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:26.778362 32212 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:26.786298 32308 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.31.117.62:33801 every 8 connection(s)
I20260812 06:18:26.786305 32212 rpc_server.cc:307] RPC server started. Bound to: 127.31.117.62:33801
I20260812 06:18:26.788667 32309 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:26.794292 32309 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 2b4bde84d11e40dfac5cc6bcfa255c4a: Bootstrap starting.
I20260812 06:18:26.796743 32309 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 2b4bde84d11e40dfac5cc6bcfa255c4a: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:26.797717 32309 log.cc:826] T 00000000000000000000000000000000 P 2b4bde84d11e40dfac5cc6bcfa255c4a: Log is configured to *not* fsync() on all Append() calls
I20260812 06:18:26.799522 32309 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 2b4bde84d11e40dfac5cc6bcfa255c4a: No bootstrap required, opened a new log
I20260812 06:18:26.802506 32309 raft_consensus.cc:359] T 00000000000000000000000000000000 P 2b4bde84d11e40dfac5cc6bcfa255c4a [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2b4bde84d11e40dfac5cc6bcfa255c4a" member_type: VOTER }
I20260812 06:18:26.802682 32309 raft_consensus.cc:385] T 00000000000000000000000000000000 P 2b4bde84d11e40dfac5cc6bcfa255c4a [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:26.802780 32309 raft_consensus.cc:740] T 00000000000000000000000000000000 P 2b4bde84d11e40dfac5cc6bcfa255c4a [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 2b4bde84d11e40dfac5cc6bcfa255c4a, State: Initialized, Role: FOLLOWER
I20260812 06:18:26.803438 32309 consensus_queue.cc:260] T 00000000000000000000000000000000 P 2b4bde84d11e40dfac5cc6bcfa255c4a [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: "2b4bde84d11e40dfac5cc6bcfa255c4a" member_type: VOTER }
I20260812 06:18:26.803606 32309 raft_consensus.cc:399] T 00000000000000000000000000000000 P 2b4bde84d11e40dfac5cc6bcfa255c4a [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:26.803699 32309 raft_consensus.cc:493] T 00000000000000000000000000000000 P 2b4bde84d11e40dfac5cc6bcfa255c4a [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:26.803850 32309 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 2b4bde84d11e40dfac5cc6bcfa255c4a [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:26.804677 32309 raft_consensus.cc:515] T 00000000000000000000000000000000 P 2b4bde84d11e40dfac5cc6bcfa255c4a [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2b4bde84d11e40dfac5cc6bcfa255c4a" member_type: VOTER }
I20260812 06:18:26.805141 32309 leader_election.cc:304] T 00000000000000000000000000000000 P 2b4bde84d11e40dfac5cc6bcfa255c4a [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: 2b4bde84d11e40dfac5cc6bcfa255c4a; no voters: 
I20260812 06:18:26.805485 32309 leader_election.cc:290] T 00000000000000000000000000000000 P 2b4bde84d11e40dfac5cc6bcfa255c4a [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:26.805647 32313 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 2b4bde84d11e40dfac5cc6bcfa255c4a [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:26.805899 32313 raft_consensus.cc:697] T 00000000000000000000000000000000 P 2b4bde84d11e40dfac5cc6bcfa255c4a [term 1 LEADER]: Becoming Leader. State: Replica: 2b4bde84d11e40dfac5cc6bcfa255c4a, State: Running, Role: LEADER
I20260812 06:18:26.806325 32313 consensus_queue.cc:237] T 00000000000000000000000000000000 P 2b4bde84d11e40dfac5cc6bcfa255c4a [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: "2b4bde84d11e40dfac5cc6bcfa255c4a" member_type: VOTER }
I20260812 06:18:26.806599 32309 sys_catalog.cc:565] T 00000000000000000000000000000000 P 2b4bde84d11e40dfac5cc6bcfa255c4a [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:26.808272 32314 sys_catalog.cc:455] T 00000000000000000000000000000000 P 2b4bde84d11e40dfac5cc6bcfa255c4a [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "2b4bde84d11e40dfac5cc6bcfa255c4a" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2b4bde84d11e40dfac5cc6bcfa255c4a" member_type: VOTER } }
I20260812 06:18:26.808334 32316 sys_catalog.cc:455] T 00000000000000000000000000000000 P 2b4bde84d11e40dfac5cc6bcfa255c4a [sys.catalog]: SysCatalogTable state changed. Reason: New leader 2b4bde84d11e40dfac5cc6bcfa255c4a. Latest consensus state: current_term: 1 leader_uuid: "2b4bde84d11e40dfac5cc6bcfa255c4a" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2b4bde84d11e40dfac5cc6bcfa255c4a" member_type: VOTER } }
I20260812 06:18:26.808418 32314 sys_catalog.cc:458] T 00000000000000000000000000000000 P 2b4bde84d11e40dfac5cc6bcfa255c4a [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:26.808441 32316 sys_catalog.cc:458] T 00000000000000000000000000000000 P 2b4bde84d11e40dfac5cc6bcfa255c4a [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:26.809094 32212 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
W20260812 06:18:26.810997 32338 catalog_manager.cc:1594] T 00000000000000000000000000000000 P 2b4bde84d11e40dfac5cc6bcfa255c4a: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:18:26.811060 32338 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:18:26.811131 32331 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:26.811856 32331 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:26.816238 32331 catalog_manager.cc:1383] Generated new cluster ID: c91831c2a0ab481eacac0a54dda7cf88
I20260812 06:18:26.816306 32331 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:26.822824 32331 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:26.823925 32331 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:26.831792 32331 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 2b4bde84d11e40dfac5cc6bcfa255c4a: Generated new TSK 0
I20260812 06:18:26.832607 32331 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:26.841756 32212 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:26.844691 32346 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:26.844815 32212 server_base.cc:1061] running on GCE node
W20260812 06:18:26.844789 32345 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:26.844707 32350 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:26.845155 32212 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:26.845214 32212 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:26.845245 32212 hybrid_clock.cc:648] HybridClock initialized: now 1786515506845245 us; error 0 us; skew 500 ppm
I20260812 06:18:26.846220 32212 webserver.cc:533] Webserver started at http://127.31.117.1:41015/ using document root <none> and password file <none>
I20260812 06:18:26.846396 32212 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:26.846458 32212 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:26.846534 32212 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:26.846985 32212 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515506702625-32212-0/minicluster-data/ts-0-root/instance:
uuid: "bd5ffad86bfe44408b448d64c9e57da0"
format_stamp: "Formatted at 2026-08-12 06:18:26 on dist-test-slave-gkw7"
I20260812 06:18:26.848886 32212 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:26.850191 32356 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:26.850544 32212 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.000s
I20260812 06:18:26.850611 32212 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515506702625-32212-0/minicluster-data/ts-0-root
uuid: "bd5ffad86bfe44408b448d64c9e57da0"
format_stamp: "Formatted at 2026-08-12 06:18:26 on dist-test-slave-gkw7"
I20260812 06:18:26.850706 32212 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515506702625-32212-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515506702625-32212-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515506702625-32212-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:26.863758 32212 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:26.864249 32212 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:26.864756 32212 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:26.865702 32212 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:26.865785 32212 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:26.865869 32212 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:26.865912 32212 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:26.872259 32212 rpc_server.cc:307] RPC server started. Bound to: 127.31.117.1:40777
I20260812 06:18:26.872315 32458 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.31.117.1:40777 every 8 connection(s)
I20260812 06:18:26.883764 32459 heartbeater.cc:344] Connected to a master server at 127.31.117.62:33801
I20260812 06:18:26.884126 32459 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:26.884696 32459 heartbeater.cc:507] Master 127.31.117.62:33801 requested a full tablet report, sending...
I20260812 06:18:26.886613 32212 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.0136519s
I20260812 06:18:26.886780 32255 ts_manager.cc:194] Registered new tserver with Master: bd5ffad86bfe44408b448d64c9e57da0 (127.31.117.1:40777)
I20260812 06:18:26.888430 32255 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:60944
I20260812 06:18:26.902209 32255 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:60956:
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:26.917586 32403 tablet_service.cc:1511] Processing CreateTablet for tablet 94488bce2cfb482388117e8760d7f516 (DEFAULT_TABLE table=heavy-update-compaction-test [id=8ba30a1683a24467b325259213793cd1]), partition=
I20260812 06:18:26.918083 32403 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 94488bce2cfb482388117e8760d7f516. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:26.920536 32478 tablet_bootstrap.cc:492] T 94488bce2cfb482388117e8760d7f516 P bd5ffad86bfe44408b448d64c9e57da0: Bootstrap starting.
I20260812 06:18:26.921736 32478 tablet_bootstrap.cc:654] T 94488bce2cfb482388117e8760d7f516 P bd5ffad86bfe44408b448d64c9e57da0: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:26.922927 32478 tablet_bootstrap.cc:492] T 94488bce2cfb482388117e8760d7f516 P bd5ffad86bfe44408b448d64c9e57da0: No bootstrap required, opened a new log
I20260812 06:18:26.923035 32478 ts_tablet_manager.cc:1403] T 94488bce2cfb482388117e8760d7f516 P bd5ffad86bfe44408b448d64c9e57da0: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:18:26.923511 32478 raft_consensus.cc:359] T 94488bce2cfb482388117e8760d7f516 P bd5ffad86bfe44408b448d64c9e57da0 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "bd5ffad86bfe44408b448d64c9e57da0" member_type: VOTER last_known_addr { host: "127.31.117.1" port: 40777 } }
I20260812 06:18:26.923612 32478 raft_consensus.cc:385] T 94488bce2cfb482388117e8760d7f516 P bd5ffad86bfe44408b448d64c9e57da0 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:26.923655 32478 raft_consensus.cc:740] T 94488bce2cfb482388117e8760d7f516 P bd5ffad86bfe44408b448d64c9e57da0 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: bd5ffad86bfe44408b448d64c9e57da0, State: Initialized, Role: FOLLOWER
I20260812 06:18:26.923820 32478 consensus_queue.cc:260] T 94488bce2cfb482388117e8760d7f516 P bd5ffad86bfe44408b448d64c9e57da0 [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: "bd5ffad86bfe44408b448d64c9e57da0" member_type: VOTER last_known_addr { host: "127.31.117.1" port: 40777 } }
I20260812 06:18:26.923902 32478 raft_consensus.cc:399] T 94488bce2cfb482388117e8760d7f516 P bd5ffad86bfe44408b448d64c9e57da0 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:26.923957 32478 raft_consensus.cc:493] T 94488bce2cfb482388117e8760d7f516 P bd5ffad86bfe44408b448d64c9e57da0 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:26.924028 32478 raft_consensus.cc:3060] T 94488bce2cfb482388117e8760d7f516 P bd5ffad86bfe44408b448d64c9e57da0 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:26.925369 32478 raft_consensus.cc:515] T 94488bce2cfb482388117e8760d7f516 P bd5ffad86bfe44408b448d64c9e57da0 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "bd5ffad86bfe44408b448d64c9e57da0" member_type: VOTER last_known_addr { host: "127.31.117.1" port: 40777 } }
I20260812 06:18:26.925559 32478 leader_election.cc:304] T 94488bce2cfb482388117e8760d7f516 P bd5ffad86bfe44408b448d64c9e57da0 [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: bd5ffad86bfe44408b448d64c9e57da0; no voters: 
I20260812 06:18:26.925805 32478 leader_election.cc:290] T 94488bce2cfb482388117e8760d7f516 P bd5ffad86bfe44408b448d64c9e57da0 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:26.925899 32483 raft_consensus.cc:2804] T 94488bce2cfb482388117e8760d7f516 P bd5ffad86bfe44408b448d64c9e57da0 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:26.926081 32483 raft_consensus.cc:697] T 94488bce2cfb482388117e8760d7f516 P bd5ffad86bfe44408b448d64c9e57da0 [term 1 LEADER]: Becoming Leader. State: Replica: bd5ffad86bfe44408b448d64c9e57da0, State: Running, Role: LEADER
I20260812 06:18:26.926213 32478 ts_tablet_manager.cc:1434] T 94488bce2cfb482388117e8760d7f516 P bd5ffad86bfe44408b448d64c9e57da0: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:18:26.926345 32483 consensus_queue.cc:237] T 94488bce2cfb482388117e8760d7f516 P bd5ffad86bfe44408b448d64c9e57da0 [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: "bd5ffad86bfe44408b448d64c9e57da0" member_type: VOTER last_known_addr { host: "127.31.117.1" port: 40777 } }
I20260812 06:18:26.926528 32459 heartbeater.cc:499] Master 127.31.117.62:33801 was elected leader, sending a full tablet report...
I20260812 06:18:26.929505 32255 catalog_manager.cc:5719] T 94488bce2cfb482388117e8760d7f516 P bd5ffad86bfe44408b448d64c9e57da0 reported cstate change: term changed from 0 to 1, leader changed from <none> to bd5ffad86bfe44408b448d64c9e57da0 (127.31.117.1). New cstate: current_term: 1 leader_uuid: "bd5ffad86bfe44408b448d64c9e57da0" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "bd5ffad86bfe44408b448d64c9e57da0" member_type: VOTER last_known_addr { host: "127.31.117.1" port: 40777 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:26.998212 32212 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.061s	user 0.026s	sys 0.001s
I20260812 06:18:27.123486 32460 maintenance_manager.cc:419] P bd5ffad86bfe44408b448d64c9e57da0: Scheduling FlushMRSOp(94488bce2cfb482388117e8760d7f516): perf score=15.086190
I20260812 06:18:27.292073 32365 maintenance_manager.cc:643] P bd5ffad86bfe44408b448d64c9e57da0: FlushMRSOp(94488bce2cfb482388117e8760d7f516) complete. Timing: real 0.168s	user 0.117s	sys 0.036s Metrics: {"bytes_written":12307490,"cfile_init":1,"compiler_manager_pool.queue_time_us":628,"delete_count":0,"dirs.queue_time_us":32,"dirs.run_cpu_time_us":228,"dirs.run_wall_time_us":865,"drs_written":1,"lbm_read_time_us":51,"lbm_reads_lt_1ms":4,"lbm_write_time_us":37331,"lbm_writes_lt_1ms":657,"peak_mem_usage":0,"reinsert_count":0,"rows_written":103,"thread_start_us":176,"threads_started":1,"update_count":1500}
I20260812 06:18:27.293227 32460 maintenance_manager.cc:419] P bd5ffad86bfe44408b448d64c9e57da0: Scheduling LogGCOp(94488bce2cfb482388117e8760d7f516): free 11976772 bytes of WAL
I20260812 06:18:27.293620 32365 log_reader.cc:385] T 94488bce2cfb482388117e8760d7f516: removed 1 log segments from log reader
I20260812 06:18:27.293702 32365 log.cc:1079] T 94488bce2cfb482388117e8760d7f516 P bd5ffad86bfe44408b448d64c9e57da0: Deleting log segment in path: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515506702625-32212-0/minicluster-data/ts-0-root/wals/94488bce2cfb482388117e8760d7f516/wal-000000001 (ops 1-6)
I20260812 06:18:27.296314 32365 maintenance_manager.cc:643] P bd5ffad86bfe44408b448d64c9e57da0: LogGCOp(94488bce2cfb482388117e8760d7f516) complete. Timing: real 0.003s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:18:27.296676 32460 maintenance_manager.cc:419] P bd5ffad86bfe44408b448d64c9e57da0: Scheduling UndoDeltaBlockGCOp(94488bce2cfb482388117e8760d7f516): 12308958 bytes on disk
I20260812 06:18:27.297292 32365 maintenance_manager.cc:643] P bd5ffad86bfe44408b448d64c9e57da0: UndoDeltaBlockGCOp(94488bce2cfb482388117e8760d7f516) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":64,"lbm_reads_lt_1ms":4}
I20260812 06:18:27.297757 32460 maintenance_manager.cc:419] P bd5ffad86bfe44408b448d64c9e57da0: Scheduling FlushDeltaMemStoresOp(94488bce2cfb482388117e8760d7f516): perf score=2.188937
I20260812 06:18:27.315901 32365 maintenance_manager.cc:643] P bd5ffad86bfe44408b448d64c9e57da0: FlushDeltaMemStoresOp(94488bce2cfb482388117e8760d7f516) complete. Timing: real 0.018s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5984,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:27.316593 32460 maintenance_manager.cc:419] P bd5ffad86bfe44408b448d64c9e57da0: Scheduling MajorDeltaCompactionOp(94488bce2cfb482388117e8760d7f516): perf score=1.000000
I20260812 06:18:27.451956 32365 maintenance_manager.cc:643] P bd5ffad86bfe44408b448d64c9e57da0: MajorDeltaCompactionOp(94488bce2cfb482388117e8760d7f516) complete. Timing: real 0.135s	user 0.106s	sys 0.029s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":556,"lbm_read_time_us":8500,"lbm_reads_lt_1ms":460,"lbm_write_time_us":25948,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":14848,"thread_start_us":296,"threads_started":5,"update_count":2000}
I20260812 06:18:27.452438 32460 maintenance_manager.cc:419] P bd5ffad86bfe44408b448d64c9e57da0: Scheduling FlushDeltaMemStoresOp(94488bce2cfb482388117e8760d7f516): perf score=10.126437
I20260812 06:18:27.502247 32365 maintenance_manager.cc:643] P bd5ffad86bfe44408b448d64c9e57da0: FlushDeltaMemStoresOp(94488bce2cfb482388117e8760d7f516) complete. Timing: real 0.050s	user 0.026s	sys 0.012s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17077,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:18:27.502743 32460 maintenance_manager.cc:419] P bd5ffad86bfe44408b448d64c9e57da0: Scheduling FlushDeltaMemStoresOp(94488bce2cfb482388117e8760d7f516): perf score=2.188937
I20260812 06:18:27.515707 32365 maintenance_manager.cc:643] P bd5ffad86bfe44408b448d64c9e57da0: FlushDeltaMemStoresOp(94488bce2cfb482388117e8760d7f516) complete. Timing: real 0.013s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4633,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:27.516297 32460 maintenance_manager.cc:419] P bd5ffad86bfe44408b448d64c9e57da0: Scheduling MajorDeltaCompactionOp(94488bce2cfb482388117e8760d7f516): perf score=1.000000
I20260812 06:18:27.661666 32365 maintenance_manager.cc:643] P bd5ffad86bfe44408b448d64c9e57da0: MajorDeltaCompactionOp(94488bce2cfb482388117e8760d7f516) complete. Timing: real 0.145s	user 0.107s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631313,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":532,"lbm_read_time_us":11145,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27345,"lbm_writes_lt_1ms":443,"mutex_wait_us":24,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12288,"update_count":2000}
I20260812 06:18:27.662215 32460 maintenance_manager.cc:419] P bd5ffad86bfe44408b448d64c9e57da0: Scheduling FlushDeltaMemStoresOp(94488bce2cfb482388117e8760d7f516): perf score=11.118625
I20260812 06:18:27.692003 32365 maintenance_manager.cc:643] P bd5ffad86bfe44408b448d64c9e57da0: FlushDeltaMemStoresOp(94488bce2cfb482388117e8760d7f516) complete. Timing: real 0.030s	user 0.015s	sys 0.012s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":13267,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:27.692561 32460 maintenance_manager.cc:419] P bd5ffad86bfe44408b448d64c9e57da0: Scheduling FlushDeltaMemStoresOp(94488bce2cfb482388117e8760d7f516): perf score=2.188937
I20260812 06:18:27.702641 32365 maintenance_manager.cc:643] P bd5ffad86bfe44408b448d64c9e57da0: FlushDeltaMemStoresOp(94488bce2cfb482388117e8760d7f516) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3829,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:27.703100 32460 maintenance_manager.cc:419] P bd5ffad86bfe44408b448d64c9e57da0: Scheduling MajorDeltaCompactionOp(94488bce2cfb482388117e8760d7f516): perf score=1.000000
I20260812 06:18:27.854642 32365 maintenance_manager.cc:643] P bd5ffad86bfe44408b448d64c9e57da0: MajorDeltaCompactionOp(94488bce2cfb482388117e8760d7f516) complete. Timing: real 0.151s	user 0.111s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631302,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":376,"lbm_read_time_us":11107,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27111,"lbm_writes_lt_1ms":443,"mutex_wait_us":73,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:18:27.855361 32460 maintenance_manager.cc:419] P bd5ffad86bfe44408b448d64c9e57da0: Scheduling FlushDeltaMemStoresOp(94488bce2cfb482388117e8760d7f516): perf score=10.126437
I20260812 06:18:27.900790 32365 maintenance_manager.cc:643] P bd5ffad86bfe44408b448d64c9e57da0: FlushDeltaMemStoresOp(94488bce2cfb482388117e8760d7f516) complete. Timing: real 0.045s	user 0.031s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15495,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:27.901460 32460 maintenance_manager.cc:419] P bd5ffad86bfe44408b448d64c9e57da0: Scheduling FlushDeltaMemStoresOp(94488bce2cfb482388117e8760d7f516): perf score=2.188937
I20260812 06:18:27.912851 32365 maintenance_manager.cc:643] P bd5ffad86bfe44408b448d64c9e57da0: FlushDeltaMemStoresOp(94488bce2cfb482388117e8760d7f516) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4231,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:27.913347 32460 maintenance_manager.cc:419] P bd5ffad86bfe44408b448d64c9e57da0: Scheduling MajorDeltaCompactionOp(94488bce2cfb482388117e8760d7f516): perf score=1.000000
I20260812 06:18:28.069687 32365 maintenance_manager.cc:643] P bd5ffad86bfe44408b448d64c9e57da0: MajorDeltaCompactionOp(94488bce2cfb482388117e8760d7f516) complete. Timing: real 0.156s	user 0.118s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1590,"lbm_read_time_us":12888,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25619,"lbm_writes_lt_1ms":443,"mutex_wait_us":520,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":13056,"update_count":2000}
I20260812 06:18:28.070506 32460 maintenance_manager.cc:419] P bd5ffad86bfe44408b448d64c9e57da0: Scheduling FlushDeltaMemStoresOp(94488bce2cfb482388117e8760d7f516): perf score=10.126437
I20260812 06:18:28.111954 32365 maintenance_manager.cc:643] P bd5ffad86bfe44408b448d64c9e57da0: FlushDeltaMemStoresOp(94488bce2cfb482388117e8760d7f516) complete. Timing: real 0.041s	user 0.025s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17955,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:28.112455 32460 maintenance_manager.cc:419] P bd5ffad86bfe44408b448d64c9e57da0: Scheduling FlushDeltaMemStoresOp(94488bce2cfb482388117e8760d7f516): perf score=2.188937
I20260812 06:18:28.123605 32365 maintenance_manager.cc:643] P bd5ffad86bfe44408b448d64c9e57da0: FlushDeltaMemStoresOp(94488bce2cfb482388117e8760d7f516) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4146,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:28.124233 32460 maintenance_manager.cc:419] P bd5ffad86bfe44408b448d64c9e57da0: Scheduling MajorDeltaCompactionOp(94488bce2cfb482388117e8760d7f516): perf score=1.000000
I20260812 06:18:28.255895 32365 maintenance_manager.cc:643] P bd5ffad86bfe44408b448d64c9e57da0: MajorDeltaCompactionOp(94488bce2cfb482388117e8760d7f516) complete. Timing: real 0.131s	user 0.107s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631311,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1178,"lbm_read_time_us":10610,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25460,"lbm_writes_lt_1ms":443,"mutex_wait_us":349,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":19584,"update_count":2000}
I20260812 06:18:28.256417 32460 maintenance_manager.cc:419] P bd5ffad86bfe44408b448d64c9e57da0: Scheduling FlushDeltaMemStoresOp(94488bce2cfb482388117e8760d7f516): perf score=10.126437
I20260812 06:18:28.305019 32365 maintenance_manager.cc:643] P bd5ffad86bfe44408b448d64c9e57da0: FlushDeltaMemStoresOp(94488bce2cfb482388117e8760d7f516) complete. Timing: real 0.048s	user 0.030s	sys 0.007s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17889,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:28.305583 32460 maintenance_manager.cc:419] P bd5ffad86bfe44408b448d64c9e57da0: Scheduling FlushDeltaMemStoresOp(94488bce2cfb482388117e8760d7f516): perf score=2.188937
I20260812 06:18:28.316845 32365 maintenance_manager.cc:643] P bd5ffad86bfe44408b448d64c9e57da0: FlushDeltaMemStoresOp(94488bce2cfb482388117e8760d7f516) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4309,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:28.317387 32460 maintenance_manager.cc:419] P bd5ffad86bfe44408b448d64c9e57da0: Scheduling MajorDeltaCompactionOp(94488bce2cfb482388117e8760d7f516): perf score=1.000000
I20260812 06:18:28.444880 32365 maintenance_manager.cc:643] P bd5ffad86bfe44408b448d64c9e57da0: MajorDeltaCompactionOp(94488bce2cfb482388117e8760d7f516) complete. Timing: real 0.127s	user 0.093s	sys 0.034s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631313,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":98,"lbm_read_time_us":8666,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25575,"lbm_writes_lt_1ms":443,"mutex_wait_us":20,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12672,"update_count":2000}
I20260812 06:18:28.445880 32460 maintenance_manager.cc:419] P bd5ffad86bfe44408b448d64c9e57da0: Scheduling FlushDeltaMemStoresOp(94488bce2cfb482388117e8760d7f516): perf score=10.126437
I20260812 06:18:28.489053 32365 maintenance_manager.cc:643] P bd5ffad86bfe44408b448d64c9e57da0: FlushDeltaMemStoresOp(94488bce2cfb482388117e8760d7f516) complete. Timing: real 0.043s	user 0.015s	sys 0.024s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":14414,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:28.489806 32460 maintenance_manager.cc:419] P bd5ffad86bfe44408b448d64c9e57da0: Scheduling FlushDeltaMemStoresOp(94488bce2cfb482388117e8760d7f516): perf score=2.188937
I20260812 06:18:28.500705 32365 maintenance_manager.cc:643] P bd5ffad86bfe44408b448d64c9e57da0: FlushDeltaMemStoresOp(94488bce2cfb482388117e8760d7f516) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4153,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:28.501156 32460 maintenance_manager.cc:419] P bd5ffad86bfe44408b448d64c9e57da0: Scheduling FlushMRSOp(94488bce2cfb482388117e8760d7f516): perf score=1.000000
I20260812 06:18:28.532941 32365 maintenance_manager.cc:643] P bd5ffad86bfe44408b448d64c9e57da0: FlushMRSOp(94488bce2cfb482388117e8760d7f516) complete. Timing: real 0.032s	user 0.030s	sys 0.000s Metrics: {"bytes_written":1152509,"cfile_init":1,"dirs.queue_time_us":56,"dirs.run_cpu_time_us":195,"dirs.run_wall_time_us":1247,"drs_written":1,"lbm_read_time_us":43,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1390,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:28.533812 32460 maintenance_manager.cc:419] P bd5ffad86bfe44408b448d64c9e57da0: Scheduling UndoDeltaBlockGCOp(94488bce2cfb482388117e8760d7f516): 447 bytes on disk
I20260812 06:18:28.534198 32365 maintenance_manager.cc:643] P bd5ffad86bfe44408b448d64c9e57da0: UndoDeltaBlockGCOp(94488bce2cfb482388117e8760d7f516) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":48,"lbm_reads_lt_1ms":4}
I20260812 06:18:28.534621 32460 maintenance_manager.cc:419] P bd5ffad86bfe44408b448d64c9e57da0: Scheduling MajorDeltaCompactionOp(94488bce2cfb482388117e8760d7f516): perf score=1.000000
I20260812 06:18:28.689814 32365 maintenance_manager.cc:643] P bd5ffad86bfe44408b448d64c9e57da0: MajorDeltaCompactionOp(94488bce2cfb482388117e8760d7f516) complete. Timing: real 0.155s	user 0.106s	sys 0.039s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631313,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":205,"lbm_read_time_us":8962,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24609,"lbm_writes_lt_1ms":443,"mutex_wait_us":41,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7936,"update_count":2000}
I20260812 06:18:28.690554 32460 maintenance_manager.cc:419] P bd5ffad86bfe44408b448d64c9e57da0: Scheduling LogGCOp(94488bce2cfb482388117e8760d7f516): free 121006422 bytes of WAL
I20260812 06:18:28.690824 32365 log_reader.cc:385] T 94488bce2cfb482388117e8760d7f516: removed 12 log segments from log reader
I20260812 06:18:28.690877 32365 log.cc:1079] T 94488bce2cfb482388117e8760d7f516 P bd5ffad86bfe44408b448d64c9e57da0: Deleting log segment in path: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515506702625-32212-0/minicluster-data/ts-0-root/wals/94488bce2cfb482388117e8760d7f516/wal-000000002 (ops 7-11)
I20260812 06:18:28.690928 32365 log.cc:1079] T 94488bce2cfb482388117e8760d7f516 P bd5ffad86bfe44408b448d64c9e57da0: Deleting log segment in path: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515506702625-32212-0/minicluster-data/ts-0-root/wals/94488bce2cfb482388117e8760d7f516/wal-000000003 (ops 12-16)
I20260812 06:18:28.690970 32365 log.cc:1079] T 94488bce2cfb482388117e8760d7f516 P bd5ffad86bfe44408b448d64c9e57da0: Deleting log segment in path: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515506702625-32212-0/minicluster-data/ts-0-root/wals/94488bce2cfb482388117e8760d7f516/wal-000000004 (ops 17-21)
I20260812 06:18:28.691015 32365 log.cc:1079] T 94488bce2cfb482388117e8760d7f516 P bd5ffad86bfe44408b448d64c9e57da0: Deleting log segment in path: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515506702625-32212-0/minicluster-data/ts-0-root/wals/94488bce2cfb482388117e8760d7f516/wal-000000005 (ops 22-26)
I20260812 06:18:28.691056 32365 log.cc:1079] T 94488bce2cfb482388117e8760d7f516 P bd5ffad86bfe44408b448d64c9e57da0: Deleting log segment in path: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515506702625-32212-0/minicluster-data/ts-0-root/wals/94488bce2cfb482388117e8760d7f516/wal-000000006 (ops 27-31)
I20260812 06:18:28.691098 32365 log.cc:1079] T 94488bce2cfb482388117e8760d7f516 P bd5ffad86bfe44408b448d64c9e57da0: Deleting log segment in path: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515506702625-32212-0/minicluster-data/ts-0-root/wals/94488bce2cfb482388117e8760d7f516/wal-000000007 (ops 32-36)
I20260812 06:18:28.691140 32365 log.cc:1079] T 94488bce2cfb482388117e8760d7f516 P bd5ffad86bfe44408b448d64c9e57da0: Deleting log segment in path: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515506702625-32212-0/minicluster-data/ts-0-root/wals/94488bce2cfb482388117e8760d7f516/wal-000000008 (ops 37-40)
I20260812 06:18:28.691197 32365 log.cc:1079] T 94488bce2cfb482388117e8760d7f516 P bd5ffad86bfe44408b448d64c9e57da0: Deleting log segment in path: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515506702625-32212-0/minicluster-data/ts-0-root/wals/94488bce2cfb482388117e8760d7f516/wal-000000009 (ops 41-45)
I20260812 06:18:28.691241 32365 log.cc:1079] T 94488bce2cfb482388117e8760d7f516 P bd5ffad86bfe44408b448d64c9e57da0: Deleting log segment in path: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515506702625-32212-0/minicluster-data/ts-0-root/wals/94488bce2cfb482388117e8760d7f516/wal-000000010 (ops 46-50)
I20260812 06:18:28.691282 32365 log.cc:1079] T 94488bce2cfb482388117e8760d7f516 P bd5ffad86bfe44408b448d64c9e57da0: Deleting log segment in path: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515506702625-32212-0/minicluster-data/ts-0-root/wals/94488bce2cfb482388117e8760d7f516/wal-000000011 (ops 51-55)
I20260812 06:18:28.691323 32365 log.cc:1079] T 94488bce2cfb482388117e8760d7f516 P bd5ffad86bfe44408b448d64c9e57da0: Deleting log segment in path: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515506702625-32212-0/minicluster-data/ts-0-root/wals/94488bce2cfb482388117e8760d7f516/wal-000000012 (ops 56-60)
I20260812 06:18:28.691365 32365 log.cc:1079] T 94488bce2cfb482388117e8760d7f516 P bd5ffad86bfe44408b448d64c9e57da0: Deleting log segment in path: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515506702625-32212-0/minicluster-data/ts-0-root/wals/94488bce2cfb482388117e8760d7f516/wal-000000013 (ops 61-65)
I20260812 06:18:28.721064 32365 maintenance_manager.cc:643] P bd5ffad86bfe44408b448d64c9e57da0: LogGCOp(94488bce2cfb482388117e8760d7f516) complete. Timing: real 0.030s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:18:28.721632 32460 maintenance_manager.cc:419] P bd5ffad86bfe44408b448d64c9e57da0: Scheduling FlushDeltaMemStoresOp(94488bce2cfb482388117e8760d7f516): perf score=15.087375
I20260812 06:18:28.781806 32365 maintenance_manager.cc:643] P bd5ffad86bfe44408b448d64c9e57da0: FlushDeltaMemStoresOp(94488bce2cfb482388117e8760d7f516) complete. Timing: real 0.060s	user 0.026s	sys 0.021s Metrics: {"bytes_written":16820142,"delete_count":0,"lbm_write_time_us":21274,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:18:28.782332 32460 maintenance_manager.cc:419] P bd5ffad86bfe44408b448d64c9e57da0: Scheduling FlushDeltaMemStoresOp(94488bce2cfb482388117e8760d7f516): perf score=6.157687
I20260812 06:18:28.814568 32365 maintenance_manager.cc:643] P bd5ffad86bfe44408b448d64c9e57da0: FlushDeltaMemStoresOp(94488bce2cfb482388117e8760d7f516) complete. Timing: real 0.032s	user 0.018s	sys 0.004s Metrics: {"bytes_written":7794836,"delete_count":0,"lbm_write_time_us":9337,"lbm_writes_lt_1ms":193,"reinsert_count":0,"update_count":950}
I20260812 06:18:28.815039 32460 maintenance_manager.cc:419] P bd5ffad86bfe44408b448d64c9e57da0: Scheduling MajorDeltaCompactionOp(94488bce2cfb482388117e8760d7f516): perf score=1.000000
I20260812 06:18:29.038048 32365 maintenance_manager.cc:643] P bd5ffad86bfe44408b448d64c9e57da0: MajorDeltaCompactionOp(94488bce2cfb482388117e8760d7f516) complete. Timing: real 0.223s	user 0.138s	sys 0.072s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28836135,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":3562,"lbm_read_time_us":15121,"lbm_reads_lt_1ms":664,"lbm_write_time_us":38063,"lbm_writes_lt_1ms":643,"mutex_wait_us":3053,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":3000}
I20260812 06:18:29.038887 32460 maintenance_manager.cc:419] P bd5ffad86bfe44408b448d64c9e57da0: Scheduling FlushDeltaMemStoresOp(94488bce2cfb482388117e8760d7f516): perf score=18.063937
I20260812 06:18:29.120393 32365 maintenance_manager.cc:643] P bd5ffad86bfe44408b448d64c9e57da0: FlushDeltaMemStoresOp(94488bce2cfb482388117e8760d7f516) complete. Timing: real 0.081s	user 0.035s	sys 0.042s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":32099,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":502,"reinsert_count":0,"update_count":2500}
I20260812 06:18:29.120959 32460 maintenance_manager.cc:419] P bd5ffad86bfe44408b448d64c9e57da0: Scheduling FlushDeltaMemStoresOp(94488bce2cfb482388117e8760d7f516): perf score=2.188937
I20260812 06:18:29.134816 32365 maintenance_manager.cc:643] P bd5ffad86bfe44408b448d64c9e57da0: FlushDeltaMemStoresOp(94488bce2cfb482388117e8760d7f516) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4861,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:29.135272 32460 maintenance_manager.cc:419] P bd5ffad86bfe44408b448d64c9e57da0: Scheduling FlushDeltaMemStoresOp(94488bce2cfb482388117e8760d7f516): perf score=2.188937
I20260812 06:18:29.146245 32365 maintenance_manager.cc:643] P bd5ffad86bfe44408b448d64c9e57da0: FlushDeltaMemStoresOp(94488bce2cfb482388117e8760d7f516) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4103,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:29.146692 32460 maintenance_manager.cc:419] P bd5ffad86bfe44408b448d64c9e57da0: Scheduling MajorDeltaCompactionOp(94488bce2cfb482388117e8760d7f516): perf score=1.000000
I20260812 06:18:29.394590 32365 maintenance_manager.cc:643] P bd5ffad86bfe44408b448d64c9e57da0: MajorDeltaCompactionOp(94488bce2cfb482388117e8760d7f516) complete. Timing: real 0.248s	user 0.192s	sys 0.054s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":32938667,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":660,"lbm_read_time_us":17414,"lbm_reads_lt_1ms":773,"lbm_write_time_us":43610,"lbm_writes_lt_1ms":743,"mutex_wait_us":91,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":3200,"update_count":3500}
I20260812 06:18:29.395207 32460 maintenance_manager.cc:419] P bd5ffad86bfe44408b448d64c9e57da0: Scheduling FlushDeltaMemStoresOp(94488bce2cfb482388117e8760d7f516): perf score=16.079562
I20260812 06:18:29.474588 32365 maintenance_manager.cc:643] P bd5ffad86bfe44408b448d64c9e57da0: FlushDeltaMemStoresOp(94488bce2cfb482388117e8760d7f516) complete. Timing: real 0.079s	user 0.051s	sys 0.016s Metrics: {"bytes_written":18009848,"delete_count":0,"lbm_write_time_us":32847,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":440,"reinsert_count":0,"update_count":2195}
I20260812 06:18:29.475132 32460 maintenance_manager.cc:419] P bd5ffad86bfe44408b448d64c9e57da0: Scheduling FlushDeltaMemStoresOp(94488bce2cfb482388117e8760d7f516): perf score=5.165500
I20260812 06:18:29.494590 32365 maintenance_manager.cc:643] P bd5ffad86bfe44408b448d64c9e57da0: FlushDeltaMemStoresOp(94488bce2cfb482388117e8760d7f516) complete. Timing: real 0.019s	user 0.014s	sys 0.004s Metrics: {"bytes_written":6605144,"delete_count":0,"lbm_write_time_us":7424,"lbm_writes_lt_1ms":164,"reinsert_count":0,"update_count":805}
I20260812 06:18:29.495112 32460 maintenance_manager.cc:419] P bd5ffad86bfe44408b448d64c9e57da0: Scheduling MajorDeltaCompactionOp(94488bce2cfb482388117e8760d7f516): perf score=1.000000
I20260812 06:18:29.723831 32365 maintenance_manager.cc:643] P bd5ffad86bfe44408b448d64c9e57da0: MajorDeltaCompactionOp(94488bce2cfb482388117e8760d7f516) complete. Timing: real 0.229s	user 0.168s	sys 0.048s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28836149,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1373,"lbm_read_time_us":15110,"lbm_reads_lt_1ms":672,"lbm_write_time_us":38298,"lbm_writes_lt_1ms":643,"mutex_wait_us":340,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":18048,"update_count":3000}
I20260812 06:18:29.724391 32460 maintenance_manager.cc:419] P bd5ffad86bfe44408b448d64c9e57da0: Scheduling FlushDeltaMemStoresOp(94488bce2cfb482388117e8760d7f516): perf score=18.063937
I20260812 06:18:29.795225 32365 maintenance_manager.cc:643] P bd5ffad86bfe44408b448d64c9e57da0: FlushDeltaMemStoresOp(94488bce2cfb482388117e8760d7f516) complete. Timing: real 0.071s	user 0.041s	sys 0.021s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":28613,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:29.795787 32460 maintenance_manager.cc:419] P bd5ffad86bfe44408b448d64c9e57da0: Scheduling FlushDeltaMemStoresOp(94488bce2cfb482388117e8760d7f516): perf score=2.188937
I20260812 06:18:29.807622 32365 maintenance_manager.cc:643] P bd5ffad86bfe44408b448d64c9e57da0: FlushDeltaMemStoresOp(94488bce2cfb482388117e8760d7f516) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4239,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:29.808286 32460 maintenance_manager.cc:419] P bd5ffad86bfe44408b448d64c9e57da0: Scheduling MajorDeltaCompactionOp(94488bce2cfb482388117e8760d7f516): perf score=1.000000
I20260812 06:18:30.012259 32365 maintenance_manager.cc:643] P bd5ffad86bfe44408b448d64c9e57da0: MajorDeltaCompactionOp(94488bce2cfb482388117e8760d7f516) complete. Timing: real 0.204s	user 0.152s	sys 0.051s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28836139,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":361,"lbm_read_time_us":14512,"lbm_reads_lt_1ms":672,"lbm_write_time_us":34966,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"update_count":3000}
I20260812 06:18:30.012952 32460 maintenance_manager.cc:419] P bd5ffad86bfe44408b448d64c9e57da0: Scheduling FlushDeltaMemStoresOp(94488bce2cfb482388117e8760d7f516): perf score=14.095187
I20260812 06:18:30.074760 32365 maintenance_manager.cc:643] P bd5ffad86bfe44408b448d64c9e57da0: FlushDeltaMemStoresOp(94488bce2cfb482388117e8760d7f516) complete. Timing: real 0.058s	user 0.025s	sys 0.032s Metrics: {"bytes_written":16409898,"delete_count":0,"lbm_write_time_us":26214,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:30.075244 32460 maintenance_manager.cc:419] P bd5ffad86bfe44408b448d64c9e57da0: Scheduling FlushDeltaMemStoresOp(94488bce2cfb482388117e8760d7f516): perf score=2.188937
I20260812 06:18:30.097347 32365 maintenance_manager.cc:643] P bd5ffad86bfe44408b448d64c9e57da0: FlushDeltaMemStoresOp(94488bce2cfb482388117e8760d7f516) complete. Timing: real 0.022s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4423,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:30.097851 32460 maintenance_manager.cc:419] P bd5ffad86bfe44408b448d64c9e57da0: Scheduling FlushDeltaMemStoresOp(94488bce2cfb482388117e8760d7f516): perf score=2.188937
I20260812 06:18:30.108327 32365 maintenance_manager.cc:643] P bd5ffad86bfe44408b448d64c9e57da0: FlushDeltaMemStoresOp(94488bce2cfb482388117e8760d7f516) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3978,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:30.108937 32460 maintenance_manager.cc:419] P bd5ffad86bfe44408b448d64c9e57da0: Scheduling FlushMRSOp(94488bce2cfb482388117e8760d7f516): perf score=1.000000
I20260812 06:18:30.143612 32365 maintenance_manager.cc:643] P bd5ffad86bfe44408b448d64c9e57da0: FlushMRSOp(94488bce2cfb482388117e8760d7f516) complete. Timing: real 0.034s	user 0.029s	sys 0.004s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":77,"dirs.run_cpu_time_us":180,"dirs.run_wall_time_us":1544,"drs_written":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1689,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:18:30.144456 32460 maintenance_manager.cc:419] P bd5ffad86bfe44408b448d64c9e57da0: Scheduling LogGCOp(94488bce2cfb482388117e8760d7f516): free 124710254 bytes of WAL
I20260812 06:18:30.144740 32365 log_reader.cc:385] T 94488bce2cfb482388117e8760d7f516: removed 12 log segments from log reader
I20260812 06:18:30.144804 32365 log.cc:1079] T 94488bce2cfb482388117e8760d7f516 P bd5ffad86bfe44408b448d64c9e57da0: Deleting log segment in path: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515506702625-32212-0/minicluster-data/ts-0-root/wals/94488bce2cfb482388117e8760d7f516/wal-000000014 (ops 66-70)
I20260812 06:18:30.144842 32365 log.cc:1079] T 94488bce2cfb482388117e8760d7f516 P bd5ffad86bfe44408b448d64c9e57da0: Deleting log segment in path: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515506702625-32212-0/minicluster-data/ts-0-root/wals/94488bce2cfb482388117e8760d7f516/wal-000000015 (ops 71-75)
I20260812 06:18:30.144876 32365 log.cc:1079] T 94488bce2cfb482388117e8760d7f516 P bd5ffad86bfe44408b448d64c9e57da0: Deleting log segment in path: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515506702625-32212-0/minicluster-data/ts-0-root/wals/94488bce2cfb482388117e8760d7f516/wal-000000016 (ops 76-80)
I20260812 06:18:30.144904 32365 log.cc:1079] T 94488bce2cfb482388117e8760d7f516 P bd5ffad86bfe44408b448d64c9e57da0: Deleting log segment in path: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515506702625-32212-0/minicluster-data/ts-0-root/wals/94488bce2cfb482388117e8760d7f516/wal-000000017 (ops 81-85)
I20260812 06:18:30.144934 32365 log.cc:1079] T 94488bce2cfb482388117e8760d7f516 P bd5ffad86bfe44408b448d64c9e57da0: Deleting log segment in path: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515506702625-32212-0/minicluster-data/ts-0-root/wals/94488bce2cfb482388117e8760d7f516/wal-000000018 (ops 86-90)
I20260812 06:18:30.144961 32365 log.cc:1079] T 94488bce2cfb482388117e8760d7f516 P bd5ffad86bfe44408b448d64c9e57da0: Deleting log segment in path: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515506702625-32212-0/minicluster-data/ts-0-root/wals/94488bce2cfb482388117e8760d7f516/wal-000000019 (ops 91-95)
I20260812 06:18:30.144984 32365 log.cc:1079] T 94488bce2cfb482388117e8760d7f516 P bd5ffad86bfe44408b448d64c9e57da0: Deleting log segment in path: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515506702625-32212-0/minicluster-data/ts-0-root/wals/94488bce2cfb482388117e8760d7f516/wal-000000020 (ops 96-100)
I20260812 06:18:30.145015 32365 log.cc:1079] T 94488bce2cfb482388117e8760d7f516 P bd5ffad86bfe44408b448d64c9e57da0: Deleting log segment in path: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515506702625-32212-0/minicluster-data/ts-0-root/wals/94488bce2cfb482388117e8760d7f516/wal-000000021 (ops 101-105)
I20260812 06:18:30.145040 32365 log.cc:1079] T 94488bce2cfb482388117e8760d7f516 P bd5ffad86bfe44408b448d64c9e57da0: Deleting log segment in path: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515506702625-32212-0/minicluster-data/ts-0-root/wals/94488bce2cfb482388117e8760d7f516/wal-000000022 (ops 106-110)
I20260812 06:18:30.145072 32365 log.cc:1079] T 94488bce2cfb482388117e8760d7f516 P bd5ffad86bfe44408b448d64c9e57da0: Deleting log segment in path: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515506702625-32212-0/minicluster-data/ts-0-root/wals/94488bce2cfb482388117e8760d7f516/wal-000000023 (ops 111-115)
I20260812 06:18:30.145102 32365 log.cc:1079] T 94488bce2cfb482388117e8760d7f516 P bd5ffad86bfe44408b448d64c9e57da0: Deleting log segment in path: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515506702625-32212-0/minicluster-data/ts-0-root/wals/94488bce2cfb482388117e8760d7f516/wal-000000024 (ops 116-120)
I20260812 06:18:30.145128 32365 log.cc:1079] T 94488bce2cfb482388117e8760d7f516 P bd5ffad86bfe44408b448d64c9e57da0: Deleting log segment in path: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515506702625-32212-0/minicluster-data/ts-0-root/wals/94488bce2cfb482388117e8760d7f516/wal-000000025 (ops 121-125)
I20260812 06:18:30.179916 32365 maintenance_manager.cc:643] P bd5ffad86bfe44408b448d64c9e57da0: LogGCOp(94488bce2cfb482388117e8760d7f516) complete. Timing: real 0.035s	user 0.002s	sys 0.031s Metrics: {}
I20260812 06:18:30.180405 32460 maintenance_manager.cc:419] P bd5ffad86bfe44408b448d64c9e57da0: Scheduling FlushDeltaMemStoresOp(94488bce2cfb482388117e8760d7f516): perf score=2.188937
I20260812 06:18:30.203184 32365 maintenance_manager.cc:643] P bd5ffad86bfe44408b448d64c9e57da0: FlushDeltaMemStoresOp(94488bce2cfb482388117e8760d7f516) complete. Timing: real 0.023s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4588,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:30.203701 32460 maintenance_manager.cc:419] P bd5ffad86bfe44408b448d64c9e57da0: Scheduling UndoDeltaBlockGCOp(94488bce2cfb482388117e8760d7f516): 482 bytes on disk
I20260812 06:18:30.204129 32365 maintenance_manager.cc:643] P bd5ffad86bfe44408b448d64c9e57da0: UndoDeltaBlockGCOp(94488bce2cfb482388117e8760d7f516) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4}
I20260812 06:18:30.204625 32460 maintenance_manager.cc:419] P bd5ffad86bfe44408b448d64c9e57da0: Scheduling FlushDeltaMemStoresOp(94488bce2cfb482388117e8760d7f516): perf score=2.188937
I20260812 06:18:30.215547 32365 maintenance_manager.cc:643] P bd5ffad86bfe44408b448d64c9e57da0: FlushDeltaMemStoresOp(94488bce2cfb482388117e8760d7f516) complete. Timing: real 0.011s	user 0.007s	sys 0.002s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4130,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:30.216249 32460 maintenance_manager.cc:419] P bd5ffad86bfe44408b448d64c9e57da0: Scheduling MajorDeltaCompactionOp(94488bce2cfb482388117e8760d7f516): perf score=1.000000
I20260812 06:18:30.470134 32365 maintenance_manager.cc:643] P bd5ffad86bfe44408b448d64c9e57da0: MajorDeltaCompactionOp(94488bce2cfb482388117e8760d7f516) complete. Timing: real 0.254s	user 0.178s	sys 0.072s Metrics: {"cfile_cache_miss":835,"cfile_cache_miss_bytes":37041312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":9643,"lbm_read_time_us":18429,"lbm_reads_lt_1ms":875,"lbm_write_time_us":45681,"lbm_writes_lt_1ms":843,"mutex_wait_us":3287,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":10496,"thread_start_us":82,"threads_started":1,"update_count":4000}
I20260812 06:18:30.470937 32460 maintenance_manager.cc:419] P bd5ffad86bfe44408b448d64c9e57da0: Scheduling FlushDeltaMemStoresOp(94488bce2cfb482388117e8760d7f516): perf score=18.063937
I20260812 06:18:30.526424 32365 maintenance_manager.cc:643] P bd5ffad86bfe44408b448d64c9e57da0: FlushDeltaMemStoresOp(94488bce2cfb482388117e8760d7f516) complete. Timing: real 0.055s	user 0.031s	sys 0.023s Metrics: {"bytes_written":20512318,"delete_count":0,"lbm_write_time_us":24467,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:30.526921 32460 maintenance_manager.cc:419] P bd5ffad86bfe44408b448d64c9e57da0: Scheduling FlushDeltaMemStoresOp(94488bce2cfb482388117e8760d7f516): perf score=2.188937
I20260812 06:18:30.543967 32365 maintenance_manager.cc:643] P bd5ffad86bfe44408b448d64c9e57da0: FlushDeltaMemStoresOp(94488bce2cfb482388117e8760d7f516) complete. Timing: real 0.017s	user 0.006s	sys 0.009s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6576,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:30.544519 32460 maintenance_manager.cc:419] P bd5ffad86bfe44408b448d64c9e57da0: Scheduling MajorDeltaCompactionOp(94488bce2cfb482388117e8760d7f516): perf score=1.000000
I20260812 06:18:30.712960 32365 maintenance_manager.cc:643] P bd5ffad86bfe44408b448d64c9e57da0: MajorDeltaCompactionOp(94488bce2cfb482388117e8760d7f516) complete. Timing: real 0.168s	user 0.127s	sys 0.041s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28836139,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1336,"lbm_read_time_us":10551,"lbm_reads_lt_1ms":664,"lbm_write_time_us":36478,"lbm_writes_lt_1ms":643,"mutex_wait_us":575,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":3000}
I20260812 06:18:30.713734 32460 maintenance_manager.cc:419] P bd5ffad86bfe44408b448d64c9e57da0: Scheduling FlushDeltaMemStoresOp(94488bce2cfb482388117e8760d7f516): perf score=14.095187
I20260812 06:18:30.761229 32365 maintenance_manager.cc:643] P bd5ffad86bfe44408b448d64c9e57da0: FlushDeltaMemStoresOp(94488bce2cfb482388117e8760d7f516) complete. Timing: real 0.047s	user 0.030s	sys 0.013s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20257,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:30.761828 32460 maintenance_manager.cc:419] P bd5ffad86bfe44408b448d64c9e57da0: Scheduling FlushDeltaMemStoresOp(94488bce2cfb482388117e8760d7f516): perf score=2.188937
I20260812 06:18:30.777797 32365 maintenance_manager.cc:643] P bd5ffad86bfe44408b448d64c9e57da0: FlushDeltaMemStoresOp(94488bce2cfb482388117e8760d7f516) complete. Timing: real 0.016s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5827,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:30.778357 32460 maintenance_manager.cc:419] P bd5ffad86bfe44408b448d64c9e57da0: Scheduling MajorDeltaCompactionOp(94488bce2cfb482388117e8760d7f516): perf score=1.000000
I20260812 06:18:30.932040 32365 maintenance_manager.cc:643] P bd5ffad86bfe44408b448d64c9e57da0: MajorDeltaCompactionOp(94488bce2cfb482388117e8760d7f516) complete. Timing: real 0.153s	user 0.103s	sys 0.047s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":130,"lbm_read_time_us":9960,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30430,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1536,"update_count":2500}
I20260812 06:18:30.932648 32460 maintenance_manager.cc:419] P bd5ffad86bfe44408b448d64c9e57da0: Scheduling FlushDeltaMemStoresOp(94488bce2cfb482388117e8760d7f516): perf score=10.126437
I20260812 06:18:30.971050 32365 maintenance_manager.cc:643] P bd5ffad86bfe44408b448d64c9e57da0: FlushDeltaMemStoresOp(94488bce2cfb482388117e8760d7f516) complete. Timing: real 0.038s	user 0.016s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16968,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:30.971637 32460 maintenance_manager.cc:419] P bd5ffad86bfe44408b448d64c9e57da0: Scheduling FlushDeltaMemStoresOp(94488bce2cfb482388117e8760d7f516): perf score=2.188937
I20260812 06:18:30.988634 32365 maintenance_manager.cc:643] P bd5ffad86bfe44408b448d64c9e57da0: FlushDeltaMemStoresOp(94488bce2cfb482388117e8760d7f516) complete. Timing: real 0.017s	user 0.011s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6231,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:30.989096 32460 maintenance_manager.cc:419] P bd5ffad86bfe44408b448d64c9e57da0: Scheduling MajorDeltaCompactionOp(94488bce2cfb482388117e8760d7f516): perf score=1.000000
I20260812 06:18:31.147871 32365 maintenance_manager.cc:643] P bd5ffad86bfe44408b448d64c9e57da0: MajorDeltaCompactionOp(94488bce2cfb482388117e8760d7f516) complete. Timing: real 0.159s	user 0.122s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631311,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":945,"lbm_read_time_us":9797,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26595,"lbm_writes_lt_1ms":443,"mutex_wait_us":249,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":2000}
I20260812 06:18:31.148545 32460 maintenance_manager.cc:419] P bd5ffad86bfe44408b448d64c9e57da0: Scheduling FlushDeltaMemStoresOp(94488bce2cfb482388117e8760d7f516): perf score=14.095187
I20260812 06:18:31.214350 32365 maintenance_manager.cc:643] P bd5ffad86bfe44408b448d64c9e57da0: FlushDeltaMemStoresOp(94488bce2cfb482388117e8760d7f516) complete. Timing: real 0.066s	user 0.030s	sys 0.035s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":24311,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:31.215032 32460 maintenance_manager.cc:419] P bd5ffad86bfe44408b448d64c9e57da0: Scheduling FlushDeltaMemStoresOp(94488bce2cfb482388117e8760d7f516): perf score=2.188937
I20260812 06:18:31.226034 32365 maintenance_manager.cc:643] P bd5ffad86bfe44408b448d64c9e57da0: FlushDeltaMemStoresOp(94488bce2cfb482388117e8760d7f516) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4238,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:31.226660 32460 maintenance_manager.cc:419] P bd5ffad86bfe44408b448d64c9e57da0: Scheduling MajorDeltaCompactionOp(94488bce2cfb482388117e8760d7f516): perf score=1.000000
I20260812 06:18:31.411118 32365 maintenance_manager.cc:643] P bd5ffad86bfe44408b448d64c9e57da0: MajorDeltaCompactionOp(94488bce2cfb482388117e8760d7f516) complete. Timing: real 0.184s	user 0.122s	sys 0.055s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733722,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":284,"lbm_read_time_us":13233,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32429,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":542,"mutex_wait_us":59,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3456,"update_count":2500}
I20260812 06:18:31.411854 32460 maintenance_manager.cc:419] P bd5ffad86bfe44408b448d64c9e57da0: Scheduling FlushDeltaMemStoresOp(94488bce2cfb482388117e8760d7f516): perf score=11.118625
I20260812 06:18:31.451819 32365 maintenance_manager.cc:643] P bd5ffad86bfe44408b448d64c9e57da0: FlushDeltaMemStoresOp(94488bce2cfb482388117e8760d7f516) complete. Timing: real 0.040s	user 0.024s	sys 0.016s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":17239,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:31.452412 32460 maintenance_manager.cc:419] P bd5ffad86bfe44408b448d64c9e57da0: Scheduling FlushDeltaMemStoresOp(94488bce2cfb482388117e8760d7f516): perf score=2.188937
I20260812 06:18:31.478716 32365 maintenance_manager.cc:643] P bd5ffad86bfe44408b448d64c9e57da0: FlushDeltaMemStoresOp(94488bce2cfb482388117e8760d7f516) complete. Timing: real 0.026s	user 0.006s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6337,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:31.479193 32460 maintenance_manager.cc:419] P bd5ffad86bfe44408b448d64c9e57da0: Scheduling FlushDeltaMemStoresOp(94488bce2cfb482388117e8760d7f516): perf score=2.188937
I20260812 06:18:31.490164 32365 maintenance_manager.cc:643] P bd5ffad86bfe44408b448d64c9e57da0: FlushDeltaMemStoresOp(94488bce2cfb482388117e8760d7f516) complete. Timing: real 0.011s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4098,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:31.490661 32460 maintenance_manager.cc:419] P bd5ffad86bfe44408b448d64c9e57da0: Scheduling MajorDeltaCompactionOp(94488bce2cfb482388117e8760d7f516): perf score=1.000000
I20260812 06:18:31.681747 32365 maintenance_manager.cc:643] P bd5ffad86bfe44408b448d64c9e57da0: MajorDeltaCompactionOp(94488bce2cfb482388117e8760d7f516) complete. Timing: real 0.191s	user 0.123s	sys 0.056s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24733836,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":295,"lbm_read_time_us":12279,"lbm_reads_lt_1ms":573,"lbm_write_time_us":30926,"lbm_writes_lt_1ms":543,"mutex_wait_us":26,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":760960,"update_count":2500}
I20260812 06:18:31.682687 32460 maintenance_manager.cc:419] P bd5ffad86bfe44408b448d64c9e57da0: Scheduling FlushDeltaMemStoresOp(94488bce2cfb482388117e8760d7f516): perf score=14.095187
I20260812 06:18:31.737979 32365 maintenance_manager.cc:643] P bd5ffad86bfe44408b448d64c9e57da0: FlushDeltaMemStoresOp(94488bce2cfb482388117e8760d7f516) complete. Timing: real 0.055s	user 0.028s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22969,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:31.738476 32460 maintenance_manager.cc:419] P bd5ffad86bfe44408b448d64c9e57da0: Scheduling FlushDeltaMemStoresOp(94488bce2cfb482388117e8760d7f516): perf score=2.188937
I20260812 06:18:31.750437 32365 maintenance_manager.cc:643] P bd5ffad86bfe44408b448d64c9e57da0: FlushDeltaMemStoresOp(94488bce2cfb482388117e8760d7f516) complete. Timing: real 0.012s	user 0.009s	sys 0.002s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4107,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:31.750959 32460 maintenance_manager.cc:419] P bd5ffad86bfe44408b448d64c9e57da0: Scheduling FlushMRSOp(94488bce2cfb482388117e8760d7f516): perf score=1.000000
I20260812 06:18:31.785452 32365 maintenance_manager.cc:643] P bd5ffad86bfe44408b448d64c9e57da0: FlushMRSOp(94488bce2cfb482388117e8760d7f516) complete. Timing: real 0.034s	user 0.032s	sys 0.001s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":80,"dirs.run_cpu_time_us":234,"dirs.run_wall_time_us":1298,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1744,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:18:31.786283 32460 maintenance_manager.cc:419] P bd5ffad86bfe44408b448d64c9e57da0: Scheduling LogGCOp(94488bce2cfb482388117e8760d7f516): free 133024683 bytes of WAL
I20260812 06:18:31.786517 32365 log_reader.cc:385] T 94488bce2cfb482388117e8760d7f516: removed 13 log segments from log reader
I20260812 06:18:31.786577 32365 log.cc:1079] T 94488bce2cfb482388117e8760d7f516 P bd5ffad86bfe44408b448d64c9e57da0: Deleting log segment in path: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515506702625-32212-0/minicluster-data/ts-0-root/wals/94488bce2cfb482388117e8760d7f516/wal-000000026 (ops 126-130)
I20260812 06:18:31.786628 32365 log.cc:1079] T 94488bce2cfb482388117e8760d7f516 P bd5ffad86bfe44408b448d64c9e57da0: Deleting log segment in path: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515506702625-32212-0/minicluster-data/ts-0-root/wals/94488bce2cfb482388117e8760d7f516/wal-000000027 (ops 131-135)
I20260812 06:18:31.786688 32365 log.cc:1079] T 94488bce2cfb482388117e8760d7f516 P bd5ffad86bfe44408b448d64c9e57da0: Deleting log segment in path: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515506702625-32212-0/minicluster-data/ts-0-root/wals/94488bce2cfb482388117e8760d7f516/wal-000000028 (ops 136-140)
I20260812 06:18:31.786731 32365 log.cc:1079] T 94488bce2cfb482388117e8760d7f516 P bd5ffad86bfe44408b448d64c9e57da0: Deleting log segment in path: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515506702625-32212-0/minicluster-data/ts-0-root/wals/94488bce2cfb482388117e8760d7f516/wal-000000029 (ops 141-145)
I20260812 06:18:31.786770 32365 log.cc:1079] T 94488bce2cfb482388117e8760d7f516 P bd5ffad86bfe44408b448d64c9e57da0: Deleting log segment in path: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515506702625-32212-0/minicluster-data/ts-0-root/wals/94488bce2cfb482388117e8760d7f516/wal-000000030 (ops 146-150)
I20260812 06:18:31.786809 32365 log.cc:1079] T 94488bce2cfb482388117e8760d7f516 P bd5ffad86bfe44408b448d64c9e57da0: Deleting log segment in path: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515506702625-32212-0/minicluster-data/ts-0-root/wals/94488bce2cfb482388117e8760d7f516/wal-000000031 (ops 151-155)
I20260812 06:18:31.786847 32365 log.cc:1079] T 94488bce2cfb482388117e8760d7f516 P bd5ffad86bfe44408b448d64c9e57da0: Deleting log segment in path: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515506702625-32212-0/minicluster-data/ts-0-root/wals/94488bce2cfb482388117e8760d7f516/wal-000000032 (ops 156-160)
I20260812 06:18:31.786886 32365 log.cc:1079] T 94488bce2cfb482388117e8760d7f516 P bd5ffad86bfe44408b448d64c9e57da0: Deleting log segment in path: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515506702625-32212-0/minicluster-data/ts-0-root/wals/94488bce2cfb482388117e8760d7f516/wal-000000033 (ops 161-165)
I20260812 06:18:31.786924 32365 log.cc:1079] T 94488bce2cfb482388117e8760d7f516 P bd5ffad86bfe44408b448d64c9e57da0: Deleting log segment in path: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515506702625-32212-0/minicluster-data/ts-0-root/wals/94488bce2cfb482388117e8760d7f516/wal-000000034 (ops 166-170)
I20260812 06:18:31.786962 32365 log.cc:1079] T 94488bce2cfb482388117e8760d7f516 P bd5ffad86bfe44408b448d64c9e57da0: Deleting log segment in path: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515506702625-32212-0/minicluster-data/ts-0-root/wals/94488bce2cfb482388117e8760d7f516/wal-000000035 (ops 171-175)
I20260812 06:18:31.787000 32365 log.cc:1079] T 94488bce2cfb482388117e8760d7f516 P bd5ffad86bfe44408b448d64c9e57da0: Deleting log segment in path: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515506702625-32212-0/minicluster-data/ts-0-root/wals/94488bce2cfb482388117e8760d7f516/wal-000000036 (ops 176-180)
I20260812 06:18:31.787038 32365 log.cc:1079] T 94488bce2cfb482388117e8760d7f516 P bd5ffad86bfe44408b448d64c9e57da0: Deleting log segment in path: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515506702625-32212-0/minicluster-data/ts-0-root/wals/94488bce2cfb482388117e8760d7f516/wal-000000037 (ops 181-184)
I20260812 06:18:31.787076 32365 log.cc:1079] T 94488bce2cfb482388117e8760d7f516 P bd5ffad86bfe44408b448d64c9e57da0: Deleting log segment in path: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515506702625-32212-0/minicluster-data/ts-0-root/wals/94488bce2cfb482388117e8760d7f516/wal-000000038 (ops 185-189)
I20260812 06:18:31.817451 32365 maintenance_manager.cc:643] P bd5ffad86bfe44408b448d64c9e57da0: LogGCOp(94488bce2cfb482388117e8760d7f516) complete. Timing: real 0.031s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:18:31.817914 32460 maintenance_manager.cc:419] P bd5ffad86bfe44408b448d64c9e57da0: Scheduling FlushDeltaMemStoresOp(94488bce2cfb482388117e8760d7f516): perf score=3.181125
I20260812 06:18:31.832142 32365 maintenance_manager.cc:643] P bd5ffad86bfe44408b448d64c9e57da0: FlushDeltaMemStoresOp(94488bce2cfb482388117e8760d7f516) complete. Timing: real 0.014s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4512902,"delete_count":0,"lbm_write_time_us":4640,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:31.832638 32460 maintenance_manager.cc:419] P bd5ffad86bfe44408b448d64c9e57da0: Scheduling UndoDeltaBlockGCOp(94488bce2cfb482388117e8760d7f516): 493 bytes on disk
I20260812 06:18:31.833084 32365 maintenance_manager.cc:643] P bd5ffad86bfe44408b448d64c9e57da0: UndoDeltaBlockGCOp(94488bce2cfb482388117e8760d7f516) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":64,"lbm_reads_lt_1ms":4}
I20260812 06:18:31.833700 32460 maintenance_manager.cc:419] P bd5ffad86bfe44408b448d64c9e57da0: Scheduling FlushDeltaMemStoresOp(94488bce2cfb482388117e8760d7f516): perf score=2.188937
I20260812 06:18:31.847798 32365 maintenance_manager.cc:643] P bd5ffad86bfe44408b448d64c9e57da0: FlushDeltaMemStoresOp(94488bce2cfb482388117e8760d7f516) complete. Timing: real 0.014s	user 0.006s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5259,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:31.848400 32460 maintenance_manager.cc:419] P bd5ffad86bfe44408b448d64c9e57da0: Scheduling MajorDeltaCompactionOp(94488bce2cfb482388117e8760d7f516): perf score=1.000000
I20260812 06:18:32.045475 32212 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.047s	user 1.897s	sys 0.136s
I20260812 06:18:32.079257 32365 maintenance_manager.cc:643] P bd5ffad86bfe44408b448d64c9e57da0: MajorDeltaCompactionOp(94488bce2cfb482388117e8760d7f516) complete. Timing: real 0.231s	user 0.141s	sys 0.088s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32938774,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"lbm_read_time_us":18698,"lbm_reads_lt_1ms":770,"lbm_write_time_us":36544,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":3500}
I20260812 06:18:32.079851 32460 maintenance_manager.cc:419] P bd5ffad86bfe44408b448d64c9e57da0: Scheduling FlushDeltaMemStoresOp(94488bce2cfb482388117e8760d7f516): perf score=14.095187
I20260812 06:18:32.112962 32365 maintenance_manager.cc:643] P bd5ffad86bfe44408b448d64c9e57da0: FlushDeltaMemStoresOp(94488bce2cfb482388117e8760d7f516) complete. Timing: real 0.033s	user 0.016s	sys 0.016s Metrics: {"bytes_written":16409899,"delete_count":0,"lbm_write_time_us":16261,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":3200,"update_count":2000}
I20260812 06:18:32.113482 32460 maintenance_manager.cc:419] P bd5ffad86bfe44408b448d64c9e57da0: Scheduling MajorDeltaCompactionOp(94488bce2cfb482388117e8760d7f516): perf score=1.000000
I20260812 06:18:32.161661 32212 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.116s	user 0.004s	sys 0.000s
I20260812 06:18:32.162339 32212 tablet_server.cc:179] TabletServer@127.31.117.1:0 shutting down...
I20260812 06:18:32.266613 32365 maintenance_manager.cc:643] P bd5ffad86bfe44408b448d64c9e57da0: MajorDeltaCompactionOp(94488bce2cfb482388117e8760d7f516) complete. Timing: real 0.153s	user 0.123s	sys 0.028s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20631190,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":1633,"lbm_read_time_us":13915,"lbm_reads_lt_1ms":467,"lbm_write_time_us":30680,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":442,"mutex_wait_us":372,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":20992,"update_count":2000}
I20260812 06:18:32.267503 32212 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:32.267926 32212 tablet_replica.cc:333] T 94488bce2cfb482388117e8760d7f516 P bd5ffad86bfe44408b448d64c9e57da0: stopping tablet replica
I20260812 06:18:32.268168 32212 raft_consensus.cc:2243] T 94488bce2cfb482388117e8760d7f516 P bd5ffad86bfe44408b448d64c9e57da0 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:32.268414 32212 raft_consensus.cc:2272] T 94488bce2cfb482388117e8760d7f516 P bd5ffad86bfe44408b448d64c9e57da0 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:32.284422 32212 tablet_server.cc:196] TabletServer@127.31.117.1:0 shutdown complete.
I20260812 06:18:32.307832 32212 master.cc:562] Master@127.31.117.62:33801 shutting down...
I20260812 06:18:32.311396 32212 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 2b4bde84d11e40dfac5cc6bcfa255c4a [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:32.311573 32212 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 2b4bde84d11e40dfac5cc6bcfa255c4a [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:32.311638 32212 tablet_replica.cc:333] T 00000000000000000000000000000000 P 2b4bde84d11e40dfac5cc6bcfa255c4a: stopping tablet replica
I20260812 06:18:32.323999 32212 master.cc:584] Master@127.31.117.62:33801 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5706 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:18:32.419333 32212 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.31.117.62:42497
I20260812 06:18:32.419741 32212 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:32.422187 32519 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:32.422294 32212 server_base.cc:1061] running on GCE node
W20260812 06:18:32.422309 32516 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:32.422309 32515 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:32.422735 32212 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:32.422796 32212 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:32.422819 32212 hybrid_clock.cc:648] HybridClock initialized: now 1786515512422818 us; error 0 us; skew 500 ppm
I20260812 06:18:32.423749 32212 webserver.cc:533] Webserver started at http://127.31.117.62:46525/ using document root <none> and password file <none>
I20260812 06:18:32.423933 32212 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:32.424000 32212 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:32.424081 32212 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:32.424499 32212 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515506702625-32212-0/minicluster-data/master-0-root/instance:
uuid: "9ce5f068b4164ba7a54d43e5d8218b1b"
format_stamp: "Formatted at 2026-08-12 06:18:32 on dist-test-slave-gkw7"
I20260812 06:18:32.426263 32212 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:32.427237 32527 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:32.427474 32212 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:32.427562 32212 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515506702625-32212-0/minicluster-data/master-0-root
uuid: "9ce5f068b4164ba7a54d43e5d8218b1b"
format_stamp: "Formatted at 2026-08-12 06:18:32 on dist-test-slave-gkw7"
I20260812 06:18:32.427642 32212 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515506702625-32212-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515506702625-32212-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515506702625-32212-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:32.441094 32212 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:32.441504 32212 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:32.445519 32212 rpc_server.cc:307] RPC server started. Bound to: 127.31.117.62:42497
I20260812 06:18:32.447921 32617 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.31.117.62:42497 every 8 connection(s)
I20260812 06:18:32.453688 32618 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:32.465739 32618 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 9ce5f068b4164ba7a54d43e5d8218b1b: Bootstrap starting.
I20260812 06:18:32.466575 32618 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 9ce5f068b4164ba7a54d43e5d8218b1b: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:32.467639 32618 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 9ce5f068b4164ba7a54d43e5d8218b1b: No bootstrap required, opened a new log
I20260812 06:18:32.468001 32618 raft_consensus.cc:359] T 00000000000000000000000000000000 P 9ce5f068b4164ba7a54d43e5d8218b1b [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9ce5f068b4164ba7a54d43e5d8218b1b" member_type: VOTER }
I20260812 06:18:32.468086 32618 raft_consensus.cc:385] T 00000000000000000000000000000000 P 9ce5f068b4164ba7a54d43e5d8218b1b [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:32.468109 32618 raft_consensus.cc:740] T 00000000000000000000000000000000 P 9ce5f068b4164ba7a54d43e5d8218b1b [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 9ce5f068b4164ba7a54d43e5d8218b1b, State: Initialized, Role: FOLLOWER
I20260812 06:18:32.468269 32618 consensus_queue.cc:260] T 00000000000000000000000000000000 P 9ce5f068b4164ba7a54d43e5d8218b1b [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: "9ce5f068b4164ba7a54d43e5d8218b1b" member_type: VOTER }
I20260812 06:18:32.468364 32618 raft_consensus.cc:399] T 00000000000000000000000000000000 P 9ce5f068b4164ba7a54d43e5d8218b1b [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:32.468389 32618 raft_consensus.cc:493] T 00000000000000000000000000000000 P 9ce5f068b4164ba7a54d43e5d8218b1b [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:32.468425 32618 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 9ce5f068b4164ba7a54d43e5d8218b1b [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:32.469085 32618 raft_consensus.cc:515] T 00000000000000000000000000000000 P 9ce5f068b4164ba7a54d43e5d8218b1b [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9ce5f068b4164ba7a54d43e5d8218b1b" member_type: VOTER }
I20260812 06:18:32.469201 32618 leader_election.cc:304] T 00000000000000000000000000000000 P 9ce5f068b4164ba7a54d43e5d8218b1b [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: 9ce5f068b4164ba7a54d43e5d8218b1b; no voters: 
I20260812 06:18:32.469372 32618 leader_election.cc:290] T 00000000000000000000000000000000 P 9ce5f068b4164ba7a54d43e5d8218b1b [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:32.469501 32624 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 9ce5f068b4164ba7a54d43e5d8218b1b [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:32.469772 32624 raft_consensus.cc:697] T 00000000000000000000000000000000 P 9ce5f068b4164ba7a54d43e5d8218b1b [term 1 LEADER]: Becoming Leader. State: Replica: 9ce5f068b4164ba7a54d43e5d8218b1b, State: Running, Role: LEADER
I20260812 06:18:32.469880 32618 sys_catalog.cc:565] T 00000000000000000000000000000000 P 9ce5f068b4164ba7a54d43e5d8218b1b [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:32.469936 32624 consensus_queue.cc:237] T 00000000000000000000000000000000 P 9ce5f068b4164ba7a54d43e5d8218b1b [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: "9ce5f068b4164ba7a54d43e5d8218b1b" member_type: VOTER }
I20260812 06:18:32.470391 32625 sys_catalog.cc:455] T 00000000000000000000000000000000 P 9ce5f068b4164ba7a54d43e5d8218b1b [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "9ce5f068b4164ba7a54d43e5d8218b1b" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9ce5f068b4164ba7a54d43e5d8218b1b" member_type: VOTER } }
I20260812 06:18:32.470504 32625 sys_catalog.cc:458] T 00000000000000000000000000000000 P 9ce5f068b4164ba7a54d43e5d8218b1b [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:32.470403 32626 sys_catalog.cc:455] T 00000000000000000000000000000000 P 9ce5f068b4164ba7a54d43e5d8218b1b [sys.catalog]: SysCatalogTable state changed. Reason: New leader 9ce5f068b4164ba7a54d43e5d8218b1b. Latest consensus state: current_term: 1 leader_uuid: "9ce5f068b4164ba7a54d43e5d8218b1b" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9ce5f068b4164ba7a54d43e5d8218b1b" member_type: VOTER } }
I20260812 06:18:32.470570 32626 sys_catalog.cc:458] T 00000000000000000000000000000000 P 9ce5f068b4164ba7a54d43e5d8218b1b [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:32.471079 32631 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:32.471848 32631 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:32.472059 32212 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:32.473714 32631 catalog_manager.cc:1383] Generated new cluster ID: ce210aa5a9c34959b24a9fa5de3e7406
I20260812 06:18:32.473773 32631 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:32.492290 32631 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:32.492930 32631 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:32.501056 32631 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 9ce5f068b4164ba7a54d43e5d8218b1b: Generated new TSK 0
I20260812 06:18:32.501329 32631 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:32.504416 32212 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:32.506690 32650 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:32.506707 32653 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:32.506781 32655 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:32.507055 32212 server_base.cc:1061] running on GCE node
I20260812 06:18:32.507256 32212 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:32.507297 32212 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:32.507313 32212 hybrid_clock.cc:648] HybridClock initialized: now 1786515512507312 us; error 0 us; skew 500 ppm
I20260812 06:18:32.508153 32212 webserver.cc:533] Webserver started at http://127.31.117.1:45995/ using document root <none> and password file <none>
I20260812 06:18:32.508312 32212 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:32.508356 32212 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:32.508407 32212 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:32.508757 32212 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515506702625-32212-0/minicluster-data/ts-0-root/instance:
uuid: "2d465b03569440adadbe2672966db0c0"
format_stamp: "Formatted at 2026-08-12 06:18:32 on dist-test-slave-gkw7"
I20260812 06:18:32.510367 32212 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:18:32.511580 32666 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:32.511857 32212 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:18:32.511922 32212 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515506702625-32212-0/minicluster-data/ts-0-root
uuid: "2d465b03569440adadbe2672966db0c0"
format_stamp: "Formatted at 2026-08-12 06:18:32 on dist-test-slave-gkw7"
I20260812 06:18:32.512025 32212 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515506702625-32212-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515506702625-32212-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515506702625-32212-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:32.538494 32212 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:32.539196 32212 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:32.539618 32212 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:32.540161 32212 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:32.540201 32212 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:32.540261 32212 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:32.540302 32212 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:32.545053 32212 rpc_server.cc:307] RPC server started. Bound to: 127.31.117.1:33343
I20260812 06:18:32.545086   300 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.31.117.1:33343 every 8 connection(s)
I20260812 06:18:32.554414   302 heartbeater.cc:344] Connected to a master server at 127.31.117.62:42497
I20260812 06:18:32.554543   302 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:32.554828   302 heartbeater.cc:507] Master 127.31.117.62:42497 requested a full tablet report, sending...
I20260812 06:18:32.555576 32554 ts_manager.cc:194] Registered new tserver with Master: 2d465b03569440adadbe2672966db0c0 (127.31.117.1:33343)
I20260812 06:18:32.555744 32212 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.010158459s
I20260812 06:18:32.556423 32554 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:37172
I20260812 06:18:32.563381 32554 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:37174:
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:32.572840 32711 tablet_service.cc:1511] Processing CreateTablet for tablet 4c164e5ecfcc4dc7ad217804776f500a (DEFAULT_TABLE table=heavy-update-compaction-test [id=7811b1c879664dcf8f8b48a70dae781d]), partition=
I20260812 06:18:32.573226 32711 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 4c164e5ecfcc4dc7ad217804776f500a. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:32.575549   321 tablet_bootstrap.cc:492] T 4c164e5ecfcc4dc7ad217804776f500a P 2d465b03569440adadbe2672966db0c0: Bootstrap starting.
I20260812 06:18:32.576453   321 tablet_bootstrap.cc:654] T 4c164e5ecfcc4dc7ad217804776f500a P 2d465b03569440adadbe2672966db0c0: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:32.577713   321 tablet_bootstrap.cc:492] T 4c164e5ecfcc4dc7ad217804776f500a P 2d465b03569440adadbe2672966db0c0: No bootstrap required, opened a new log
I20260812 06:18:32.577859   321 ts_tablet_manager.cc:1403] T 4c164e5ecfcc4dc7ad217804776f500a P 2d465b03569440adadbe2672966db0c0: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:32.578392   321 raft_consensus.cc:359] T 4c164e5ecfcc4dc7ad217804776f500a P 2d465b03569440adadbe2672966db0c0 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2d465b03569440adadbe2672966db0c0" member_type: VOTER last_known_addr { host: "127.31.117.1" port: 33343 } }
I20260812 06:18:32.578481   321 raft_consensus.cc:385] T 4c164e5ecfcc4dc7ad217804776f500a P 2d465b03569440adadbe2672966db0c0 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:32.578504   321 raft_consensus.cc:740] T 4c164e5ecfcc4dc7ad217804776f500a P 2d465b03569440adadbe2672966db0c0 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 2d465b03569440adadbe2672966db0c0, State: Initialized, Role: FOLLOWER
I20260812 06:18:32.578676   321 consensus_queue.cc:260] T 4c164e5ecfcc4dc7ad217804776f500a P 2d465b03569440adadbe2672966db0c0 [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: "2d465b03569440adadbe2672966db0c0" member_type: VOTER last_known_addr { host: "127.31.117.1" port: 33343 } }
I20260812 06:18:32.578774   321 raft_consensus.cc:399] T 4c164e5ecfcc4dc7ad217804776f500a P 2d465b03569440adadbe2672966db0c0 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:32.578841   321 raft_consensus.cc:493] T 4c164e5ecfcc4dc7ad217804776f500a P 2d465b03569440adadbe2672966db0c0 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:32.578899   321 raft_consensus.cc:3060] T 4c164e5ecfcc4dc7ad217804776f500a P 2d465b03569440adadbe2672966db0c0 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:32.579629   321 raft_consensus.cc:515] T 4c164e5ecfcc4dc7ad217804776f500a P 2d465b03569440adadbe2672966db0c0 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2d465b03569440adadbe2672966db0c0" member_type: VOTER last_known_addr { host: "127.31.117.1" port: 33343 } }
I20260812 06:18:32.579797   321 leader_election.cc:304] T 4c164e5ecfcc4dc7ad217804776f500a P 2d465b03569440adadbe2672966db0c0 [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: 2d465b03569440adadbe2672966db0c0; no voters: 
I20260812 06:18:32.580029   321 leader_election.cc:290] T 4c164e5ecfcc4dc7ad217804776f500a P 2d465b03569440adadbe2672966db0c0 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:32.580160   323 raft_consensus.cc:2804] T 4c164e5ecfcc4dc7ad217804776f500a P 2d465b03569440adadbe2672966db0c0 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:32.580402   321 ts_tablet_manager.cc:1434] T 4c164e5ecfcc4dc7ad217804776f500a P 2d465b03569440adadbe2672966db0c0: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:18:32.580418   323 raft_consensus.cc:697] T 4c164e5ecfcc4dc7ad217804776f500a P 2d465b03569440adadbe2672966db0c0 [term 1 LEADER]: Becoming Leader. State: Replica: 2d465b03569440adadbe2672966db0c0, State: Running, Role: LEADER
I20260812 06:18:32.580420   302 heartbeater.cc:499] Master 127.31.117.62:42497 was elected leader, sending a full tablet report...
I20260812 06:18:32.580615   323 consensus_queue.cc:237] T 4c164e5ecfcc4dc7ad217804776f500a P 2d465b03569440adadbe2672966db0c0 [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: "2d465b03569440adadbe2672966db0c0" member_type: VOTER last_known_addr { host: "127.31.117.1" port: 33343 } }
I20260812 06:18:32.582116 32554 catalog_manager.cc:5719] T 4c164e5ecfcc4dc7ad217804776f500a P 2d465b03569440adadbe2672966db0c0 reported cstate change: term changed from 0 to 1, leader changed from <none> to 2d465b03569440adadbe2672966db0c0 (127.31.117.1). New cstate: current_term: 1 leader_uuid: "2d465b03569440adadbe2672966db0c0" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2d465b03569440adadbe2672966db0c0" member_type: VOTER last_known_addr { host: "127.31.117.1" port: 33343 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:32.644553 32212 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.056s	user 0.024s	sys 0.000s
I20260812 06:18:32.796241   305 maintenance_manager.cc:419] P 2d465b03569440adadbe2672966db0c0: Scheduling FlushMRSOp(4c164e5ecfcc4dc7ad217804776f500a): perf score=19.054940
I20260812 06:18:32.959182 32672 maintenance_manager.cc:643] P 2d465b03569440adadbe2672966db0c0: FlushMRSOp(4c164e5ecfcc4dc7ad217804776f500a) complete. Timing: real 0.163s	user 0.114s	sys 0.047s Metrics: {"bytes_written":12307491,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":78,"dirs.run_cpu_time_us":207,"dirs.run_wall_time_us":955,"drs_written":1,"lbm_read_time_us":81,"lbm_reads_lt_1ms":4,"lbm_write_time_us":43161,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1500}
I20260812 06:18:32.959970   305 maintenance_manager.cc:419] P 2d465b03569440adadbe2672966db0c0: Scheduling LogGCOp(4c164e5ecfcc4dc7ad217804776f500a): free 20743880 bytes of WAL
I20260812 06:18:32.960232 32672 log_reader.cc:385] T 4c164e5ecfcc4dc7ad217804776f500a: removed 2 log segments from log reader
I20260812 06:18:32.960294 32672 log.cc:1079] T 4c164e5ecfcc4dc7ad217804776f500a P 2d465b03569440adadbe2672966db0c0: Deleting log segment in path: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515506702625-32212-0/minicluster-data/ts-0-root/wals/4c164e5ecfcc4dc7ad217804776f500a/wal-000000001 (ops 1-6)
I20260812 06:18:32.960342 32672 log.cc:1079] T 4c164e5ecfcc4dc7ad217804776f500a P 2d465b03569440adadbe2672966db0c0: Deleting log segment in path: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515506702625-32212-0/minicluster-data/ts-0-root/wals/4c164e5ecfcc4dc7ad217804776f500a/wal-000000002 (ops 7-11)
I20260812 06:18:32.965229 32672 maintenance_manager.cc:643] P 2d465b03569440adadbe2672966db0c0: LogGCOp(4c164e5ecfcc4dc7ad217804776f500a) complete. Timing: real 0.005s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:18:32.965700   305 maintenance_manager.cc:419] P 2d465b03569440adadbe2672966db0c0: Scheduling UndoDeltaBlockGCOp(4c164e5ecfcc4dc7ad217804776f500a): 16411393 bytes on disk
I20260812 06:18:32.966114 32672 maintenance_manager.cc:643] P 2d465b03569440adadbe2672966db0c0: UndoDeltaBlockGCOp(4c164e5ecfcc4dc7ad217804776f500a) 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:32.966536   305 maintenance_manager.cc:419] P 2d465b03569440adadbe2672966db0c0: Scheduling FlushDeltaMemStoresOp(4c164e5ecfcc4dc7ad217804776f500a): perf score=3.181125
I20260812 06:18:32.987854 32672 maintenance_manager.cc:643] P 2d465b03569440adadbe2672966db0c0: FlushDeltaMemStoresOp(4c164e5ecfcc4dc7ad217804776f500a) complete. Timing: real 0.021s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":5183,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:32.988335   305 maintenance_manager.cc:419] P 2d465b03569440adadbe2672966db0c0: Scheduling FlushDeltaMemStoresOp(4c164e5ecfcc4dc7ad217804776f500a): perf score=2.188937
I20260812 06:18:33.007930 32672 maintenance_manager.cc:643] P 2d465b03569440adadbe2672966db0c0: FlushDeltaMemStoresOp(4c164e5ecfcc4dc7ad217804776f500a) complete. Timing: real 0.019s	user 0.004s	sys 0.013s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3711,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:33.008534   305 maintenance_manager.cc:419] P 2d465b03569440adadbe2672966db0c0: Scheduling MajorDeltaCompactionOp(4c164e5ecfcc4dc7ad217804776f500a): perf score=1.000000
I20260812 06:18:33.219043 32672 maintenance_manager.cc:643] P 2d465b03569440adadbe2672966db0c0: MajorDeltaCompactionOp(4c164e5ecfcc4dc7ad217804776f500a) complete. Timing: real 0.210s	user 0.138s	sys 0.060s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774799,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":328,"lbm_read_time_us":14858,"lbm_reads_lt_1ms":569,"lbm_write_time_us":31371,"lbm_writes_lt_1ms":543,"mutex_wait_us":32,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9216,"thread_start_us":356,"threads_started":5,"update_count":2500}
I20260812 06:18:33.219587   305 maintenance_manager.cc:419] P 2d465b03569440adadbe2672966db0c0: Scheduling FlushDeltaMemStoresOp(4c164e5ecfcc4dc7ad217804776f500a): perf score=14.095187
I20260812 06:18:33.272622 32672 maintenance_manager.cc:643] P 2d465b03569440adadbe2672966db0c0: FlushDeltaMemStoresOp(4c164e5ecfcc4dc7ad217804776f500a) complete. Timing: real 0.053s	user 0.039s	sys 0.008s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22426,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:33.273123   305 maintenance_manager.cc:419] P 2d465b03569440adadbe2672966db0c0: Scheduling FlushDeltaMemStoresOp(4c164e5ecfcc4dc7ad217804776f500a): perf score=2.188937
I20260812 06:18:33.288934 32672 maintenance_manager.cc:643] P 2d465b03569440adadbe2672966db0c0: FlushDeltaMemStoresOp(4c164e5ecfcc4dc7ad217804776f500a) complete. Timing: real 0.016s	user 0.006s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5844,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:33.289413   305 maintenance_manager.cc:419] P 2d465b03569440adadbe2672966db0c0: Scheduling MajorDeltaCompactionOp(4c164e5ecfcc4dc7ad217804776f500a): perf score=1.000000
I20260812 06:18:33.472518 32672 maintenance_manager.cc:643] P 2d465b03569440adadbe2672966db0c0: MajorDeltaCompactionOp(4c164e5ecfcc4dc7ad217804776f500a) complete. Timing: real 0.183s	user 0.102s	sys 0.061s 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":363,"lbm_read_time_us":11570,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28640,"lbm_writes_lt_1ms":543,"mutex_wait_us":22,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":37632,"update_count":2500}
I20260812 06:18:33.473206   305 maintenance_manager.cc:419] P 2d465b03569440adadbe2672966db0c0: Scheduling FlushDeltaMemStoresOp(4c164e5ecfcc4dc7ad217804776f500a): perf score=14.095187
I20260812 06:18:33.521432 32672 maintenance_manager.cc:643] P 2d465b03569440adadbe2672966db0c0: FlushDeltaMemStoresOp(4c164e5ecfcc4dc7ad217804776f500a) complete. Timing: real 0.048s	user 0.020s	sys 0.024s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":21262,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:33.522024   305 maintenance_manager.cc:419] P 2d465b03569440adadbe2672966db0c0: Scheduling FlushDeltaMemStoresOp(4c164e5ecfcc4dc7ad217804776f500a): perf score=2.188937
I20260812 06:18:33.535305 32672 maintenance_manager.cc:643] P 2d465b03569440adadbe2672966db0c0: FlushDeltaMemStoresOp(4c164e5ecfcc4dc7ad217804776f500a) complete. Timing: real 0.013s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5309,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:33.535848   305 maintenance_manager.cc:419] P 2d465b03569440adadbe2672966db0c0: Scheduling MajorDeltaCompactionOp(4c164e5ecfcc4dc7ad217804776f500a): perf score=1.000000
I20260812 06:18:33.697111 32672 maintenance_manager.cc:643] P 2d465b03569440adadbe2672966db0c0: MajorDeltaCompactionOp(4c164e5ecfcc4dc7ad217804776f500a) complete. Timing: real 0.161s	user 0.133s	sys 0.024s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":665,"lbm_read_time_us":10762,"lbm_reads_lt_1ms":564,"lbm_write_time_us":32295,"lbm_writes_lt_1ms":543,"mutex_wait_us":21,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":50688,"update_count":2500}
I20260812 06:18:33.697732   305 maintenance_manager.cc:419] P 2d465b03569440adadbe2672966db0c0: Scheduling FlushDeltaMemStoresOp(4c164e5ecfcc4dc7ad217804776f500a): perf score=11.118625
I20260812 06:18:33.747452 32672 maintenance_manager.cc:643] P 2d465b03569440adadbe2672966db0c0: FlushDeltaMemStoresOp(4c164e5ecfcc4dc7ad217804776f500a) complete. Timing: real 0.050s	user 0.019s	sys 0.025s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":21978,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:33.747929   305 maintenance_manager.cc:419] P 2d465b03569440adadbe2672966db0c0: Scheduling FlushDeltaMemStoresOp(4c164e5ecfcc4dc7ad217804776f500a): perf score=2.188937
I20260812 06:18:33.765189 32672 maintenance_manager.cc:643] P 2d465b03569440adadbe2672966db0c0: FlushDeltaMemStoresOp(4c164e5ecfcc4dc7ad217804776f500a) complete. Timing: real 0.017s	user 0.011s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6609,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:33.765703   305 maintenance_manager.cc:419] P 2d465b03569440adadbe2672966db0c0: Scheduling FlushDeltaMemStoresOp(4c164e5ecfcc4dc7ad217804776f500a): perf score=2.188937
I20260812 06:18:33.775417 32672 maintenance_manager.cc:643] P 2d465b03569440adadbe2672966db0c0: FlushDeltaMemStoresOp(4c164e5ecfcc4dc7ad217804776f500a) complete. Timing: real 0.010s	user 0.003s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3819,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:33.775848   305 maintenance_manager.cc:419] P 2d465b03569440adadbe2672966db0c0: Scheduling MajorDeltaCompactionOp(4c164e5ecfcc4dc7ad217804776f500a): perf score=1.000000
I20260812 06:18:33.936676 32672 maintenance_manager.cc:643] P 2d465b03569440adadbe2672966db0c0: MajorDeltaCompactionOp(4c164e5ecfcc4dc7ad217804776f500a) complete. Timing: real 0.161s	user 0.109s	sys 0.040s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774800,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":623,"lbm_read_time_us":11649,"lbm_reads_lt_1ms":573,"lbm_write_time_us":30526,"lbm_writes_lt_1ms":543,"mutex_wait_us":289,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":19200,"update_count":2500}
I20260812 06:18:33.940922   305 maintenance_manager.cc:419] P 2d465b03569440adadbe2672966db0c0: Scheduling FlushDeltaMemStoresOp(4c164e5ecfcc4dc7ad217804776f500a): perf score=14.095187
I20260812 06:18:33.996317 32672 maintenance_manager.cc:643] P 2d465b03569440adadbe2672966db0c0: FlushDeltaMemStoresOp(4c164e5ecfcc4dc7ad217804776f500a) complete. Timing: real 0.055s	user 0.020s	sys 0.032s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24387,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:33.996913   305 maintenance_manager.cc:419] P 2d465b03569440adadbe2672966db0c0: Scheduling FlushDeltaMemStoresOp(4c164e5ecfcc4dc7ad217804776f500a): perf score=2.188937
I20260812 06:18:34.013115 32672 maintenance_manager.cc:643] P 2d465b03569440adadbe2672966db0c0: FlushDeltaMemStoresOp(4c164e5ecfcc4dc7ad217804776f500a) complete. Timing: real 0.016s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4924,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:34.013891   305 maintenance_manager.cc:419] P 2d465b03569440adadbe2672966db0c0: Scheduling MajorDeltaCompactionOp(4c164e5ecfcc4dc7ad217804776f500a): perf score=1.000000
I20260812 06:18:34.176491 32672 maintenance_manager.cc:643] P 2d465b03569440adadbe2672966db0c0: MajorDeltaCompactionOp(4c164e5ecfcc4dc7ad217804776f500a) complete. Timing: real 0.162s	user 0.119s	sys 0.041s 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":268,"lbm_read_time_us":9768,"lbm_reads_lt_1ms":564,"lbm_write_time_us":34027,"lbm_writes_lt_1ms":543,"mutex_wait_us":48,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":16000,"update_count":2500}
I20260812 06:18:34.177089   305 maintenance_manager.cc:419] P 2d465b03569440adadbe2672966db0c0: Scheduling FlushDeltaMemStoresOp(4c164e5ecfcc4dc7ad217804776f500a): perf score=14.095187
I20260812 06:18:34.231941 32672 maintenance_manager.cc:643] P 2d465b03569440adadbe2672966db0c0: FlushDeltaMemStoresOp(4c164e5ecfcc4dc7ad217804776f500a) complete. Timing: real 0.055s	user 0.024s	sys 0.028s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24860,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:34.232596   305 maintenance_manager.cc:419] P 2d465b03569440adadbe2672966db0c0: Scheduling FlushDeltaMemStoresOp(4c164e5ecfcc4dc7ad217804776f500a): perf score=2.188937
I20260812 06:18:34.252416 32672 maintenance_manager.cc:643] P 2d465b03569440adadbe2672966db0c0: FlushDeltaMemStoresOp(4c164e5ecfcc4dc7ad217804776f500a) complete. Timing: real 0.020s	user 0.000s	sys 0.014s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6617,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:34.252969   305 maintenance_manager.cc:419] P 2d465b03569440adadbe2672966db0c0: Scheduling FlushMRSOp(4c164e5ecfcc4dc7ad217804776f500a): perf score=1.000000
I20260812 06:18:34.305436 32672 maintenance_manager.cc:643] P 2d465b03569440adadbe2672966db0c0: FlushMRSOp(4c164e5ecfcc4dc7ad217804776f500a) complete. Timing: real 0.052s	user 0.030s	sys 0.001s Metrics: {"bytes_written":1275443,"cfile_init":1,"dirs.queue_time_us":68,"dirs.run_cpu_time_us":255,"dirs.run_wall_time_us":1435,"drs_written":1,"lbm_read_time_us":66,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1818,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:18:34.306216   305 maintenance_manager.cc:419] P 2d465b03569440adadbe2672966db0c0: Scheduling LogGCOp(4c164e5ecfcc4dc7ad217804776f500a): free 124257239 bytes of WAL
I20260812 06:18:34.306450 32672 log_reader.cc:385] T 4c164e5ecfcc4dc7ad217804776f500a: removed 12 log segments from log reader
I20260812 06:18:34.306493 32672 log.cc:1079] T 4c164e5ecfcc4dc7ad217804776f500a P 2d465b03569440adadbe2672966db0c0: Deleting log segment in path: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515506702625-32212-0/minicluster-data/ts-0-root/wals/4c164e5ecfcc4dc7ad217804776f500a/wal-000000003 (ops 12-16)
I20260812 06:18:34.306522 32672 log.cc:1079] T 4c164e5ecfcc4dc7ad217804776f500a P 2d465b03569440adadbe2672966db0c0: Deleting log segment in path: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515506702625-32212-0/minicluster-data/ts-0-root/wals/4c164e5ecfcc4dc7ad217804776f500a/wal-000000004 (ops 17-21)
I20260812 06:18:34.306586 32672 log.cc:1079] T 4c164e5ecfcc4dc7ad217804776f500a P 2d465b03569440adadbe2672966db0c0: Deleting log segment in path: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515506702625-32212-0/minicluster-data/ts-0-root/wals/4c164e5ecfcc4dc7ad217804776f500a/wal-000000005 (ops 22-26)
I20260812 06:18:34.306620 32672 log.cc:1079] T 4c164e5ecfcc4dc7ad217804776f500a P 2d465b03569440adadbe2672966db0c0: Deleting log segment in path: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515506702625-32212-0/minicluster-data/ts-0-root/wals/4c164e5ecfcc4dc7ad217804776f500a/wal-000000006 (ops 27-31)
I20260812 06:18:34.306680 32672 log.cc:1079] T 4c164e5ecfcc4dc7ad217804776f500a P 2d465b03569440adadbe2672966db0c0: Deleting log segment in path: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515506702625-32212-0/minicluster-data/ts-0-root/wals/4c164e5ecfcc4dc7ad217804776f500a/wal-000000007 (ops 32-36)
I20260812 06:18:34.306739 32672 log.cc:1079] T 4c164e5ecfcc4dc7ad217804776f500a P 2d465b03569440adadbe2672966db0c0: Deleting log segment in path: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515506702625-32212-0/minicluster-data/ts-0-root/wals/4c164e5ecfcc4dc7ad217804776f500a/wal-000000008 (ops 37-40)
I20260812 06:18:34.306779 32672 log.cc:1079] T 4c164e5ecfcc4dc7ad217804776f500a P 2d465b03569440adadbe2672966db0c0: Deleting log segment in path: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515506702625-32212-0/minicluster-data/ts-0-root/wals/4c164e5ecfcc4dc7ad217804776f500a/wal-000000009 (ops 41-45)
I20260812 06:18:34.306818 32672 log.cc:1079] T 4c164e5ecfcc4dc7ad217804776f500a P 2d465b03569440adadbe2672966db0c0: Deleting log segment in path: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515506702625-32212-0/minicluster-data/ts-0-root/wals/4c164e5ecfcc4dc7ad217804776f500a/wal-000000010 (ops 46-50)
I20260812 06:18:34.306856 32672 log.cc:1079] T 4c164e5ecfcc4dc7ad217804776f500a P 2d465b03569440adadbe2672966db0c0: Deleting log segment in path: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515506702625-32212-0/minicluster-data/ts-0-root/wals/4c164e5ecfcc4dc7ad217804776f500a/wal-000000011 (ops 51-55)
I20260812 06:18:34.306895 32672 log.cc:1079] T 4c164e5ecfcc4dc7ad217804776f500a P 2d465b03569440adadbe2672966db0c0: Deleting log segment in path: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515506702625-32212-0/minicluster-data/ts-0-root/wals/4c164e5ecfcc4dc7ad217804776f500a/wal-000000012 (ops 56-60)
I20260812 06:18:34.306933 32672 log.cc:1079] T 4c164e5ecfcc4dc7ad217804776f500a P 2d465b03569440adadbe2672966db0c0: Deleting log segment in path: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515506702625-32212-0/minicluster-data/ts-0-root/wals/4c164e5ecfcc4dc7ad217804776f500a/wal-000000013 (ops 61-65)
I20260812 06:18:34.306977 32672 log.cc:1079] T 4c164e5ecfcc4dc7ad217804776f500a P 2d465b03569440adadbe2672966db0c0: Deleting log segment in path: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515506702625-32212-0/minicluster-data/ts-0-root/wals/4c164e5ecfcc4dc7ad217804776f500a/wal-000000014 (ops 66-70)
I20260812 06:18:34.336540 32672 maintenance_manager.cc:643] P 2d465b03569440adadbe2672966db0c0: LogGCOp(4c164e5ecfcc4dc7ad217804776f500a) complete. Timing: real 0.030s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:18:34.336926   305 maintenance_manager.cc:419] P 2d465b03569440adadbe2672966db0c0: Scheduling FlushDeltaMemStoresOp(4c164e5ecfcc4dc7ad217804776f500a): perf score=7.149875
I20260812 06:18:34.365075 32672 maintenance_manager.cc:643] P 2d465b03569440adadbe2672966db0c0: FlushDeltaMemStoresOp(4c164e5ecfcc4dc7ad217804776f500a) complete. Timing: real 0.028s	user 0.018s	sys 0.007s Metrics: {"bytes_written":8615323,"delete_count":0,"lbm_write_time_us":12285,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:18:34.365679   305 maintenance_manager.cc:419] P 2d465b03569440adadbe2672966db0c0: Scheduling FlushDeltaMemStoresOp(4c164e5ecfcc4dc7ad217804776f500a): perf score=2.188937
I20260812 06:18:34.377315 32672 maintenance_manager.cc:643] P 2d465b03569440adadbe2672966db0c0: FlushDeltaMemStoresOp(4c164e5ecfcc4dc7ad217804776f500a) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4079,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:34.377866   305 maintenance_manager.cc:419] P 2d465b03569440adadbe2672966db0c0: Scheduling UndoDeltaBlockGCOp(4c164e5ecfcc4dc7ad217804776f500a): 482 bytes on disk
I20260812 06:18:34.378399 32672 maintenance_manager.cc:643] P 2d465b03569440adadbe2672966db0c0: UndoDeltaBlockGCOp(4c164e5ecfcc4dc7ad217804776f500a) 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:34.378964   305 maintenance_manager.cc:419] P 2d465b03569440adadbe2672966db0c0: Scheduling MajorDeltaCompactionOp(4c164e5ecfcc4dc7ad217804776f500a): perf score=1.000000
I20260812 06:18:34.615801 32672 maintenance_manager.cc:643] P 2d465b03569440adadbe2672966db0c0: MajorDeltaCompactionOp(4c164e5ecfcc4dc7ad217804776f500a) complete. Timing: real 0.237s	user 0.176s	sys 0.052s Metrics: {"cfile_cache_miss":834,"cfile_cache_miss_bytes":37082154,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":369,"lbm_read_time_us":16822,"lbm_reads_lt_1ms":874,"lbm_write_time_us":47716,"lbm_writes_lt_1ms":843,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":4864,"thread_start_us":95,"threads_started":1,"update_count":4000}
I20260812 06:18:34.616457   305 maintenance_manager.cc:419] P 2d465b03569440adadbe2672966db0c0: Scheduling FlushDeltaMemStoresOp(4c164e5ecfcc4dc7ad217804776f500a): perf score=18.063937
I20260812 06:18:34.670248 32672 maintenance_manager.cc:643] P 2d465b03569440adadbe2672966db0c0: FlushDeltaMemStoresOp(4c164e5ecfcc4dc7ad217804776f500a) complete. Timing: real 0.054s	user 0.042s	sys 0.011s Metrics: {"bytes_written":20512319,"delete_count":0,"lbm_write_time_us":23703,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:34.670722   305 maintenance_manager.cc:419] P 2d465b03569440adadbe2672966db0c0: Scheduling FlushDeltaMemStoresOp(4c164e5ecfcc4dc7ad217804776f500a): perf score=2.188937
I20260812 06:18:34.682963 32672 maintenance_manager.cc:643] P 2d465b03569440adadbe2672966db0c0: FlushDeltaMemStoresOp(4c164e5ecfcc4dc7ad217804776f500a) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3975,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:34.683621   305 maintenance_manager.cc:419] P 2d465b03569440adadbe2672966db0c0: Scheduling MajorDeltaCompactionOp(4c164e5ecfcc4dc7ad217804776f500a): perf score=1.000000
I20260812 06:18:34.855842 32672 maintenance_manager.cc:643] P 2d465b03569440adadbe2672966db0c0: MajorDeltaCompactionOp(4c164e5ecfcc4dc7ad217804776f500a) complete. Timing: real 0.172s	user 0.144s	sys 0.028s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877106,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":280,"lbm_read_time_us":13462,"lbm_reads_lt_1ms":672,"lbm_write_time_us":36416,"lbm_writes_lt_1ms":643,"mutex_wait_us":55,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":19200,"update_count":3000}
I20260812 06:18:34.856423   305 maintenance_manager.cc:419] P 2d465b03569440adadbe2672966db0c0: Scheduling FlushDeltaMemStoresOp(4c164e5ecfcc4dc7ad217804776f500a): perf score=14.095187
I20260812 06:18:34.908578 32672 maintenance_manager.cc:643] P 2d465b03569440adadbe2672966db0c0: FlushDeltaMemStoresOp(4c164e5ecfcc4dc7ad217804776f500a) complete. Timing: real 0.052s	user 0.025s	sys 0.021s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22152,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:34.909147   305 maintenance_manager.cc:419] P 2d465b03569440adadbe2672966db0c0: Scheduling FlushDeltaMemStoresOp(4c164e5ecfcc4dc7ad217804776f500a): perf score=2.188937
I20260812 06:18:34.924907 32672 maintenance_manager.cc:643] P 2d465b03569440adadbe2672966db0c0: FlushDeltaMemStoresOp(4c164e5ecfcc4dc7ad217804776f500a) complete. Timing: real 0.016s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5769,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:34.925671   305 maintenance_manager.cc:419] P 2d465b03569440adadbe2672966db0c0: Scheduling MajorDeltaCompactionOp(4c164e5ecfcc4dc7ad217804776f500a): perf score=1.000000
I20260812 06:18:35.090387 32672 maintenance_manager.cc:643] P 2d465b03569440adadbe2672966db0c0: MajorDeltaCompactionOp(4c164e5ecfcc4dc7ad217804776f500a) complete. Timing: real 0.164s	user 0.140s	sys 0.016s 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":801,"lbm_read_time_us":10173,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32448,"lbm_writes_lt_1ms":543,"mutex_wait_us":340,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11648,"update_count":2500}
I20260812 06:18:35.091050   305 maintenance_manager.cc:419] P 2d465b03569440adadbe2672966db0c0: Scheduling FlushDeltaMemStoresOp(4c164e5ecfcc4dc7ad217804776f500a): perf score=11.118625
I20260812 06:18:35.138890 32672 maintenance_manager.cc:643] P 2d465b03569440adadbe2672966db0c0: FlushDeltaMemStoresOp(4c164e5ecfcc4dc7ad217804776f500a) complete. Timing: real 0.048s	user 0.026s	sys 0.019s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":23649,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:18:35.139427   305 maintenance_manager.cc:419] P 2d465b03569440adadbe2672966db0c0: Scheduling FlushDeltaMemStoresOp(4c164e5ecfcc4dc7ad217804776f500a): perf score=2.188937
I20260812 06:18:35.161317 32672 maintenance_manager.cc:643] P 2d465b03569440adadbe2672966db0c0: FlushDeltaMemStoresOp(4c164e5ecfcc4dc7ad217804776f500a) complete. Timing: real 0.022s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4319,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:35.161813   305 maintenance_manager.cc:419] P 2d465b03569440adadbe2672966db0c0: Scheduling FlushDeltaMemStoresOp(4c164e5ecfcc4dc7ad217804776f500a): perf score=2.188937
I20260812 06:18:35.172567 32672 maintenance_manager.cc:643] P 2d465b03569440adadbe2672966db0c0: FlushDeltaMemStoresOp(4c164e5ecfcc4dc7ad217804776f500a) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4073,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:35.173077   305 maintenance_manager.cc:419] P 2d465b03569440adadbe2672966db0c0: Scheduling MajorDeltaCompactionOp(4c164e5ecfcc4dc7ad217804776f500a): perf score=1.000000
I20260812 06:18:35.371896 32672 maintenance_manager.cc:643] P 2d465b03569440adadbe2672966db0c0: MajorDeltaCompactionOp(4c164e5ecfcc4dc7ad217804776f500a) complete. Timing: real 0.199s	user 0.121s	sys 0.075s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774798,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":404,"lbm_read_time_us":13925,"lbm_reads_lt_1ms":573,"lbm_write_time_us":32722,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6400,"update_count":2500}
I20260812 06:18:35.372519   305 maintenance_manager.cc:419] P 2d465b03569440adadbe2672966db0c0: Scheduling FlushDeltaMemStoresOp(4c164e5ecfcc4dc7ad217804776f500a): perf score=14.095187
I20260812 06:18:35.426882 32672 maintenance_manager.cc:643] P 2d465b03569440adadbe2672966db0c0: FlushDeltaMemStoresOp(4c164e5ecfcc4dc7ad217804776f500a) complete. Timing: real 0.054s	user 0.041s	sys 0.012s Metrics: {"bytes_written":16409882,"delete_count":0,"lbm_write_time_us":24451,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:35.427359   305 maintenance_manager.cc:419] P 2d465b03569440adadbe2672966db0c0: Scheduling MajorDeltaCompactionOp(4c164e5ecfcc4dc7ad217804776f500a): perf score=1.000000
I20260812 06:18:35.568770 32672 maintenance_manager.cc:643] P 2d465b03569440adadbe2672966db0c0: MajorDeltaCompactionOp(4c164e5ecfcc4dc7ad217804776f500a) complete. Timing: real 0.141s	user 0.090s	sys 0.049s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672138,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":686,"lbm_read_time_us":9219,"lbm_reads_lt_1ms":467,"lbm_write_time_us":24285,"lbm_writes_lt_1ms":443,"mutex_wait_us":21,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5888,"update_count":2000}
I20260812 06:18:35.569644   305 maintenance_manager.cc:419] P 2d465b03569440adadbe2672966db0c0: Scheduling FlushDeltaMemStoresOp(4c164e5ecfcc4dc7ad217804776f500a): perf score=11.118625
I20260812 06:18:35.617714 32672 maintenance_manager.cc:643] P 2d465b03569440adadbe2672966db0c0: FlushDeltaMemStoresOp(4c164e5ecfcc4dc7ad217804776f500a) complete. Timing: real 0.048s	user 0.025s	sys 0.021s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":19835,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:35.618296   305 maintenance_manager.cc:419] P 2d465b03569440adadbe2672966db0c0: Scheduling FlushDeltaMemStoresOp(4c164e5ecfcc4dc7ad217804776f500a): perf score=2.188937
I20260812 06:18:35.638068 32672 maintenance_manager.cc:643] P 2d465b03569440adadbe2672966db0c0: FlushDeltaMemStoresOp(4c164e5ecfcc4dc7ad217804776f500a) complete. Timing: real 0.020s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4870,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:35.638522   305 maintenance_manager.cc:419] P 2d465b03569440adadbe2672966db0c0: Scheduling FlushDeltaMemStoresOp(4c164e5ecfcc4dc7ad217804776f500a): perf score=2.188937
I20260812 06:18:35.647809 32672 maintenance_manager.cc:643] P 2d465b03569440adadbe2672966db0c0: FlushDeltaMemStoresOp(4c164e5ecfcc4dc7ad217804776f500a) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3488,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:35.648228   305 maintenance_manager.cc:419] P 2d465b03569440adadbe2672966db0c0: Scheduling MajorDeltaCompactionOp(4c164e5ecfcc4dc7ad217804776f500a): perf score=1.000000
I20260812 06:18:35.840360 32672 maintenance_manager.cc:643] P 2d465b03569440adadbe2672966db0c0: MajorDeltaCompactionOp(4c164e5ecfcc4dc7ad217804776f500a) complete. Timing: real 0.192s	user 0.124s	sys 0.060s 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":1188,"lbm_read_time_us":12602,"lbm_reads_lt_1ms":573,"lbm_write_time_us":27444,"lbm_writes_lt_1ms":543,"mutex_wait_us":364,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":2500}
I20260812 06:18:35.840891   305 maintenance_manager.cc:419] P 2d465b03569440adadbe2672966db0c0: Scheduling FlushDeltaMemStoresOp(4c164e5ecfcc4dc7ad217804776f500a): perf score=14.095187
I20260812 06:18:35.892866 32672 maintenance_manager.cc:643] P 2d465b03569440adadbe2672966db0c0: FlushDeltaMemStoresOp(4c164e5ecfcc4dc7ad217804776f500a) complete. Timing: real 0.052s	user 0.031s	sys 0.015s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21798,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:35.893441   305 maintenance_manager.cc:419] P 2d465b03569440adadbe2672966db0c0: Scheduling FlushDeltaMemStoresOp(4c164e5ecfcc4dc7ad217804776f500a): perf score=2.188937
I20260812 06:18:35.905964 32672 maintenance_manager.cc:643] P 2d465b03569440adadbe2672966db0c0: FlushDeltaMemStoresOp(4c164e5ecfcc4dc7ad217804776f500a) complete. Timing: real 0.012s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4232,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:35.906711   305 maintenance_manager.cc:419] P 2d465b03569440adadbe2672966db0c0: Scheduling FlushMRSOp(4c164e5ecfcc4dc7ad217804776f500a): perf score=1.000000
I20260812 06:18:35.940518 32672 maintenance_manager.cc:643] P 2d465b03569440adadbe2672966db0c0: FlushMRSOp(4c164e5ecfcc4dc7ad217804776f500a) complete. Timing: real 0.034s	user 0.032s	sys 0.000s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":70,"dirs.run_cpu_time_us":248,"dirs.run_wall_time_us":1341,"drs_written":1,"lbm_read_time_us":44,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1682,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:18:35.941174   305 maintenance_manager.cc:419] P 2d465b03569440adadbe2672966db0c0: Scheduling LogGCOp(4c164e5ecfcc4dc7ad217804776f500a): free 133024390 bytes of WAL
I20260812 06:18:35.941417 32672 log_reader.cc:385] T 4c164e5ecfcc4dc7ad217804776f500a: removed 13 log segments from log reader
I20260812 06:18:35.941462 32672 log.cc:1079] T 4c164e5ecfcc4dc7ad217804776f500a P 2d465b03569440adadbe2672966db0c0: Deleting log segment in path: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515506702625-32212-0/minicluster-data/ts-0-root/wals/4c164e5ecfcc4dc7ad217804776f500a/wal-000000015 (ops 71-75)
I20260812 06:18:35.941493 32672 log.cc:1079] T 4c164e5ecfcc4dc7ad217804776f500a P 2d465b03569440adadbe2672966db0c0: Deleting log segment in path: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515506702625-32212-0/minicluster-data/ts-0-root/wals/4c164e5ecfcc4dc7ad217804776f500a/wal-000000016 (ops 76-80)
I20260812 06:18:35.941534 32672 log.cc:1079] T 4c164e5ecfcc4dc7ad217804776f500a P 2d465b03569440adadbe2672966db0c0: Deleting log segment in path: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515506702625-32212-0/minicluster-data/ts-0-root/wals/4c164e5ecfcc4dc7ad217804776f500a/wal-000000017 (ops 81-85)
I20260812 06:18:35.941607 32672 log.cc:1079] T 4c164e5ecfcc4dc7ad217804776f500a P 2d465b03569440adadbe2672966db0c0: Deleting log segment in path: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515506702625-32212-0/minicluster-data/ts-0-root/wals/4c164e5ecfcc4dc7ad217804776f500a/wal-000000018 (ops 86-90)
I20260812 06:18:35.941627 32672 log.cc:1079] T 4c164e5ecfcc4dc7ad217804776f500a P 2d465b03569440adadbe2672966db0c0: Deleting log segment in path: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515506702625-32212-0/minicluster-data/ts-0-root/wals/4c164e5ecfcc4dc7ad217804776f500a/wal-000000019 (ops 91-95)
I20260812 06:18:35.941679 32672 log.cc:1079] T 4c164e5ecfcc4dc7ad217804776f500a P 2d465b03569440adadbe2672966db0c0: Deleting log segment in path: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515506702625-32212-0/minicluster-data/ts-0-root/wals/4c164e5ecfcc4dc7ad217804776f500a/wal-000000020 (ops 96-100)
I20260812 06:18:35.941725 32672 log.cc:1079] T 4c164e5ecfcc4dc7ad217804776f500a P 2d465b03569440adadbe2672966db0c0: Deleting log segment in path: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515506702625-32212-0/minicluster-data/ts-0-root/wals/4c164e5ecfcc4dc7ad217804776f500a/wal-000000021 (ops 101-105)
I20260812 06:18:35.941798 32672 log.cc:1079] T 4c164e5ecfcc4dc7ad217804776f500a P 2d465b03569440adadbe2672966db0c0: Deleting log segment in path: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515506702625-32212-0/minicluster-data/ts-0-root/wals/4c164e5ecfcc4dc7ad217804776f500a/wal-000000022 (ops 106-110)
I20260812 06:18:35.941843 32672 log.cc:1079] T 4c164e5ecfcc4dc7ad217804776f500a P 2d465b03569440adadbe2672966db0c0: Deleting log segment in path: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515506702625-32212-0/minicluster-data/ts-0-root/wals/4c164e5ecfcc4dc7ad217804776f500a/wal-000000023 (ops 111-114)
I20260812 06:18:35.941862 32672 log.cc:1079] T 4c164e5ecfcc4dc7ad217804776f500a P 2d465b03569440adadbe2672966db0c0: Deleting log segment in path: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515506702625-32212-0/minicluster-data/ts-0-root/wals/4c164e5ecfcc4dc7ad217804776f500a/wal-000000024 (ops 115-119)
I20260812 06:18:35.941912 32672 log.cc:1079] T 4c164e5ecfcc4dc7ad217804776f500a P 2d465b03569440adadbe2672966db0c0: Deleting log segment in path: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515506702625-32212-0/minicluster-data/ts-0-root/wals/4c164e5ecfcc4dc7ad217804776f500a/wal-000000025 (ops 120-124)
I20260812 06:18:35.941954 32672 log.cc:1079] T 4c164e5ecfcc4dc7ad217804776f500a P 2d465b03569440adadbe2672966db0c0: Deleting log segment in path: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515506702625-32212-0/minicluster-data/ts-0-root/wals/4c164e5ecfcc4dc7ad217804776f500a/wal-000000026 (ops 125-129)
I20260812 06:18:35.941994 32672 log.cc:1079] T 4c164e5ecfcc4dc7ad217804776f500a P 2d465b03569440adadbe2672966db0c0: Deleting log segment in path: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515506702625-32212-0/minicluster-data/ts-0-root/wals/4c164e5ecfcc4dc7ad217804776f500a/wal-000000027 (ops 130-134)
I20260812 06:18:35.973167 32672 maintenance_manager.cc:643] P 2d465b03569440adadbe2672966db0c0: LogGCOp(4c164e5ecfcc4dc7ad217804776f500a) complete. Timing: real 0.032s	user 0.000s	sys 0.028s Metrics: {}
I20260812 06:18:35.973737   305 maintenance_manager.cc:419] P 2d465b03569440adadbe2672966db0c0: Scheduling UndoDeltaBlockGCOp(4c164e5ecfcc4dc7ad217804776f500a): 493 bytes on disk
I20260812 06:18:35.974387 32672 maintenance_manager.cc:643] P 2d465b03569440adadbe2672966db0c0: UndoDeltaBlockGCOp(4c164e5ecfcc4dc7ad217804776f500a) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":107,"lbm_reads_lt_1ms":4}
I20260812 06:18:35.975011   305 maintenance_manager.cc:419] P 2d465b03569440adadbe2672966db0c0: Scheduling FlushDeltaMemStoresOp(4c164e5ecfcc4dc7ad217804776f500a): perf score=3.181125
I20260812 06:18:36.003981 32672 maintenance_manager.cc:643] P 2d465b03569440adadbe2672966db0c0: FlushDeltaMemStoresOp(4c164e5ecfcc4dc7ad217804776f500a) complete. Timing: real 0.029s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":5475,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:36.004657   305 maintenance_manager.cc:419] P 2d465b03569440adadbe2672966db0c0: Scheduling FlushDeltaMemStoresOp(4c164e5ecfcc4dc7ad217804776f500a): perf score=2.188937
I20260812 06:18:36.021852 32672 maintenance_manager.cc:643] P 2d465b03569440adadbe2672966db0c0: FlushDeltaMemStoresOp(4c164e5ecfcc4dc7ad217804776f500a) complete. Timing: real 0.017s	user 0.017s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6233,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:36.022431   305 maintenance_manager.cc:419] P 2d465b03569440adadbe2672966db0c0: Scheduling MajorDeltaCompactionOp(4c164e5ecfcc4dc7ad217804776f500a): perf score=1.000000
I20260812 06:18:36.282127 32672 maintenance_manager.cc:643] P 2d465b03569440adadbe2672966db0c0: MajorDeltaCompactionOp(4c164e5ecfcc4dc7ad217804776f500a) complete. Timing: real 0.260s	user 0.169s	sys 0.083s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979740,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":807,"lbm_read_time_us":19293,"lbm_reads_lt_1ms":774,"lbm_write_time_us":39829,"lbm_writes_lt_1ms":743,"mutex_wait_us":84,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":1408,"thread_start_us":106,"threads_started":1,"update_count":3500}
I20260812 06:18:36.282877   305 maintenance_manager.cc:419] P 2d465b03569440adadbe2672966db0c0: Scheduling FlushDeltaMemStoresOp(4c164e5ecfcc4dc7ad217804776f500a): perf score=18.063937
I20260812 06:18:36.338063 32672 maintenance_manager.cc:643] P 2d465b03569440adadbe2672966db0c0: FlushDeltaMemStoresOp(4c164e5ecfcc4dc7ad217804776f500a) complete. Timing: real 0.055s	user 0.043s	sys 0.012s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":24984,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:36.338707   305 maintenance_manager.cc:419] P 2d465b03569440adadbe2672966db0c0: Scheduling MajorDeltaCompactionOp(4c164e5ecfcc4dc7ad217804776f500a): perf score=1.000000
I20260812 06:18:36.522230 32672 maintenance_manager.cc:643] P 2d465b03569440adadbe2672966db0c0: MajorDeltaCompactionOp(4c164e5ecfcc4dc7ad217804776f500a) complete. Timing: real 0.183s	user 0.131s	sys 0.052s Metrics: {"cfile_cache_miss":531,"cfile_cache_miss_bytes":24774572,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":1083,"lbm_read_time_us":12954,"lbm_reads_lt_1ms":563,"lbm_write_time_us":33582,"lbm_writes_lt_1ms":543,"mutex_wait_us":284,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3456,"update_count":2500}
I20260812 06:18:36.522974   305 maintenance_manager.cc:419] P 2d465b03569440adadbe2672966db0c0: Scheduling FlushDeltaMemStoresOp(4c164e5ecfcc4dc7ad217804776f500a): perf score=14.095187
I20260812 06:18:36.583478 32672 maintenance_manager.cc:643] P 2d465b03569440adadbe2672966db0c0: FlushDeltaMemStoresOp(4c164e5ecfcc4dc7ad217804776f500a) complete. Timing: real 0.060s	user 0.015s	sys 0.043s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20331,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:36.584152   305 maintenance_manager.cc:419] P 2d465b03569440adadbe2672966db0c0: Scheduling FlushDeltaMemStoresOp(4c164e5ecfcc4dc7ad217804776f500a): perf score=2.188937
I20260812 06:18:36.601421 32672 maintenance_manager.cc:643] P 2d465b03569440adadbe2672966db0c0: FlushDeltaMemStoresOp(4c164e5ecfcc4dc7ad217804776f500a) complete. Timing: real 0.017s	user 0.011s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6482,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:36.602094   305 maintenance_manager.cc:419] P 2d465b03569440adadbe2672966db0c0: Scheduling MajorDeltaCompactionOp(4c164e5ecfcc4dc7ad217804776f500a): perf score=1.000000
I20260812 06:18:36.806968 32672 maintenance_manager.cc:643] P 2d465b03569440adadbe2672966db0c0: MajorDeltaCompactionOp(4c164e5ecfcc4dc7ad217804776f500a) complete. Timing: real 0.205s	user 0.159s	sys 0.039s 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":971,"lbm_read_time_us":14515,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33578,"lbm_writes_lt_1ms":543,"mutex_wait_us":260,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4992,"update_count":2500}
I20260812 06:18:36.807605   305 maintenance_manager.cc:419] P 2d465b03569440adadbe2672966db0c0: Scheduling FlushDeltaMemStoresOp(4c164e5ecfcc4dc7ad217804776f500a): perf score=14.095187
I20260812 06:18:36.874977 32672 maintenance_manager.cc:643] P 2d465b03569440adadbe2672966db0c0: FlushDeltaMemStoresOp(4c164e5ecfcc4dc7ad217804776f500a) complete. Timing: real 0.067s	user 0.026s	sys 0.036s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23908,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:36.875557   305 maintenance_manager.cc:419] P 2d465b03569440adadbe2672966db0c0: Scheduling FlushDeltaMemStoresOp(4c164e5ecfcc4dc7ad217804776f500a): perf score=2.188937
I20260812 06:18:36.887044 32672 maintenance_manager.cc:643] P 2d465b03569440adadbe2672966db0c0: FlushDeltaMemStoresOp(4c164e5ecfcc4dc7ad217804776f500a) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4370,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:36.887632   305 maintenance_manager.cc:419] P 2d465b03569440adadbe2672966db0c0: Scheduling MajorDeltaCompactionOp(4c164e5ecfcc4dc7ad217804776f500a): perf score=1.000000
I20260812 06:18:37.066459 32672 maintenance_manager.cc:643] P 2d465b03569440adadbe2672966db0c0: MajorDeltaCompactionOp(4c164e5ecfcc4dc7ad217804776f500a) complete. Timing: real 0.179s	user 0.125s	sys 0.051s 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":243,"lbm_read_time_us":14216,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27657,"lbm_writes_lt_1ms":543,"mutex_wait_us":44,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3200,"update_count":2500}
I20260812 06:18:37.066998   305 maintenance_manager.cc:419] P 2d465b03569440adadbe2672966db0c0: Scheduling FlushDeltaMemStoresOp(4c164e5ecfcc4dc7ad217804776f500a): perf score=11.118625
I20260812 06:18:37.112301 32672 maintenance_manager.cc:643] P 2d465b03569440adadbe2672966db0c0: FlushDeltaMemStoresOp(4c164e5ecfcc4dc7ad217804776f500a) complete. Timing: real 0.045s	user 0.031s	sys 0.012s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":18955,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:37.112957   305 maintenance_manager.cc:419] P 2d465b03569440adadbe2672966db0c0: Scheduling FlushDeltaMemStoresOp(4c164e5ecfcc4dc7ad217804776f500a): perf score=2.188937
I20260812 06:18:37.124831 32672 maintenance_manager.cc:643] P 2d465b03569440adadbe2672966db0c0: FlushDeltaMemStoresOp(4c164e5ecfcc4dc7ad217804776f500a) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4369,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:37.125507   305 maintenance_manager.cc:419] P 2d465b03569440adadbe2672966db0c0: Scheduling MajorDeltaCompactionOp(4c164e5ecfcc4dc7ad217804776f500a): perf score=1.000000
I20260812 06:18:37.259366 32672 maintenance_manager.cc:643] P 2d465b03569440adadbe2672966db0c0: MajorDeltaCompactionOp(4c164e5ecfcc4dc7ad217804776f500a) complete. Timing: real 0.134s	user 0.096s	sys 0.037s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672269,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1145,"lbm_read_time_us":9052,"lbm_reads_lt_1ms":464,"lbm_write_time_us":26134,"lbm_writes_lt_1ms":443,"mutex_wait_us":355,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":36352,"update_count":2000}
I20260812 06:18:37.260003   305 maintenance_manager.cc:419] P 2d465b03569440adadbe2672966db0c0: Scheduling FlushDeltaMemStoresOp(4c164e5ecfcc4dc7ad217804776f500a): perf score=10.126437
I20260812 06:18:37.306131 32672 maintenance_manager.cc:643] P 2d465b03569440adadbe2672966db0c0: FlushDeltaMemStoresOp(4c164e5ecfcc4dc7ad217804776f500a) complete. Timing: real 0.046s	user 0.022s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16374,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:37.306818   305 maintenance_manager.cc:419] P 2d465b03569440adadbe2672966db0c0: Scheduling FlushDeltaMemStoresOp(4c164e5ecfcc4dc7ad217804776f500a): perf score=2.188937
I20260812 06:18:37.322672 32672 maintenance_manager.cc:643] P 2d465b03569440adadbe2672966db0c0: FlushDeltaMemStoresOp(4c164e5ecfcc4dc7ad217804776f500a) complete. Timing: real 0.016s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5926,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:37.323422   305 maintenance_manager.cc:419] P 2d465b03569440adadbe2672966db0c0: Scheduling MajorDeltaCompactionOp(4c164e5ecfcc4dc7ad217804776f500a): perf score=1.000000
I20260812 06:18:37.456770 32672 maintenance_manager.cc:643] P 2d465b03569440adadbe2672966db0c0: MajorDeltaCompactionOp(4c164e5ecfcc4dc7ad217804776f500a) complete. Timing: real 0.133s	user 0.109s	sys 0.024s 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":149,"lbm_read_time_us":10239,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25196,"lbm_writes_lt_1ms":443,"mutex_wait_us":48,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5760,"update_count":2000}
I20260812 06:18:37.457336   305 maintenance_manager.cc:419] P 2d465b03569440adadbe2672966db0c0: Scheduling FlushDeltaMemStoresOp(4c164e5ecfcc4dc7ad217804776f500a): perf score=10.126437
I20260812 06:18:37.496884 32672 maintenance_manager.cc:643] P 2d465b03569440adadbe2672966db0c0: FlushDeltaMemStoresOp(4c164e5ecfcc4dc7ad217804776f500a) complete. Timing: real 0.039s	user 0.019s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16833,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:37.497407   305 maintenance_manager.cc:419] P 2d465b03569440adadbe2672966db0c0: Scheduling FlushMRSOp(4c164e5ecfcc4dc7ad217804776f500a): perf score=1.000000
I20260812 06:18:37.555234 32672 maintenance_manager.cc:643] P 2d465b03569440adadbe2672966db0c0: FlushMRSOp(4c164e5ecfcc4dc7ad217804776f500a) complete. Timing: real 0.058s	user 0.034s	sys 0.000s Metrics: {"bytes_written":1193507,"cfile_init":1,"dirs.queue_time_us":67,"dirs.run_cpu_time_us":267,"dirs.run_wall_time_us":1392,"drs_written":1,"lbm_read_time_us":64,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2599,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:18:37.555915   305 maintenance_manager.cc:419] P 2d465b03569440adadbe2672966db0c0: Scheduling LogGCOp(4c164e5ecfcc4dc7ad217804776f500a): free 120553636 bytes of WAL
I20260812 06:18:37.556149 32672 log_reader.cc:385] T 4c164e5ecfcc4dc7ad217804776f500a: removed 12 log segments from log reader
I20260812 06:18:37.556192 32672 log.cc:1079] T 4c164e5ecfcc4dc7ad217804776f500a P 2d465b03569440adadbe2672966db0c0: Deleting log segment in path: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515506702625-32212-0/minicluster-data/ts-0-root/wals/4c164e5ecfcc4dc7ad217804776f500a/wal-000000028 (ops 135-139)
I20260812 06:18:37.556243 32672 log.cc:1079] T 4c164e5ecfcc4dc7ad217804776f500a P 2d465b03569440adadbe2672966db0c0: Deleting log segment in path: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515506702625-32212-0/minicluster-data/ts-0-root/wals/4c164e5ecfcc4dc7ad217804776f500a/wal-000000029 (ops 140-144)
I20260812 06:18:37.556275 32672 log.cc:1079] T 4c164e5ecfcc4dc7ad217804776f500a P 2d465b03569440adadbe2672966db0c0: Deleting log segment in path: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515506702625-32212-0/minicluster-data/ts-0-root/wals/4c164e5ecfcc4dc7ad217804776f500a/wal-000000030 (ops 145-149)
I20260812 06:18:37.556334 32672 log.cc:1079] T 4c164e5ecfcc4dc7ad217804776f500a P 2d465b03569440adadbe2672966db0c0: Deleting log segment in path: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515506702625-32212-0/minicluster-data/ts-0-root/wals/4c164e5ecfcc4dc7ad217804776f500a/wal-000000031 (ops 150-154)
I20260812 06:18:37.556368 32672 log.cc:1079] T 4c164e5ecfcc4dc7ad217804776f500a P 2d465b03569440adadbe2672966db0c0: Deleting log segment in path: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515506702625-32212-0/minicluster-data/ts-0-root/wals/4c164e5ecfcc4dc7ad217804776f500a/wal-000000032 (ops 155-158)
I20260812 06:18:37.556404 32672 log.cc:1079] T 4c164e5ecfcc4dc7ad217804776f500a P 2d465b03569440adadbe2672966db0c0: Deleting log segment in path: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515506702625-32212-0/minicluster-data/ts-0-root/wals/4c164e5ecfcc4dc7ad217804776f500a/wal-000000033 (ops 159-163)
I20260812 06:18:37.556440 32672 log.cc:1079] T 4c164e5ecfcc4dc7ad217804776f500a P 2d465b03569440adadbe2672966db0c0: Deleting log segment in path: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515506702625-32212-0/minicluster-data/ts-0-root/wals/4c164e5ecfcc4dc7ad217804776f500a/wal-000000034 (ops 164-168)
I20260812 06:18:37.556479 32672 log.cc:1079] T 4c164e5ecfcc4dc7ad217804776f500a P 2d465b03569440adadbe2672966db0c0: Deleting log segment in path: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515506702625-32212-0/minicluster-data/ts-0-root/wals/4c164e5ecfcc4dc7ad217804776f500a/wal-000000035 (ops 169-173)
I20260812 06:18:37.556516 32672 log.cc:1079] T 4c164e5ecfcc4dc7ad217804776f500a P 2d465b03569440adadbe2672966db0c0: Deleting log segment in path: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515506702625-32212-0/minicluster-data/ts-0-root/wals/4c164e5ecfcc4dc7ad217804776f500a/wal-000000036 (ops 174-178)
I20260812 06:18:37.556552 32672 log.cc:1079] T 4c164e5ecfcc4dc7ad217804776f500a P 2d465b03569440adadbe2672966db0c0: Deleting log segment in path: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515506702625-32212-0/minicluster-data/ts-0-root/wals/4c164e5ecfcc4dc7ad217804776f500a/wal-000000037 (ops 179-183)
I20260812 06:18:37.556588 32672 log.cc:1079] T 4c164e5ecfcc4dc7ad217804776f500a P 2d465b03569440adadbe2672966db0c0: Deleting log segment in path: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515506702625-32212-0/minicluster-data/ts-0-root/wals/4c164e5ecfcc4dc7ad217804776f500a/wal-000000038 (ops 184-188)
I20260812 06:18:37.556625 32672 log.cc:1079] T 4c164e5ecfcc4dc7ad217804776f500a P 2d465b03569440adadbe2672966db0c0: Deleting log segment in path: /tmp/dist-test-task2JonCg/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515506702625-32212-0/minicluster-data/ts-0-root/wals/4c164e5ecfcc4dc7ad217804776f500a/wal-000000039 (ops 189-192)
I20260812 06:18:37.584782 32672 maintenance_manager.cc:643] P 2d465b03569440adadbe2672966db0c0: LogGCOp(4c164e5ecfcc4dc7ad217804776f500a) complete. Timing: real 0.029s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:18:37.585269   305 maintenance_manager.cc:419] P 2d465b03569440adadbe2672966db0c0: Scheduling FlushDeltaMemStoresOp(4c164e5ecfcc4dc7ad217804776f500a): perf score=7.149875
I20260812 06:18:37.606443 32672 maintenance_manager.cc:643] P 2d465b03569440adadbe2672966db0c0: FlushDeltaMemStoresOp(4c164e5ecfcc4dc7ad217804776f500a) complete. Timing: real 0.021s	user 0.012s	sys 0.008s Metrics: {"bytes_written":8615323,"delete_count":0,"lbm_write_time_us":9073,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:18:37.606900   305 maintenance_manager.cc:419] P 2d465b03569440adadbe2672966db0c0: Scheduling FlushDeltaMemStoresOp(4c164e5ecfcc4dc7ad217804776f500a): perf score=2.188937
I20260812 06:18:37.620705 32672 maintenance_manager.cc:643] P 2d465b03569440adadbe2672966db0c0: FlushDeltaMemStoresOp(4c164e5ecfcc4dc7ad217804776f500a) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5347,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:37.621163   305 maintenance_manager.cc:419] P 2d465b03569440adadbe2672966db0c0: Scheduling UndoDeltaBlockGCOp(4c164e5ecfcc4dc7ad217804776f500a): 462 bytes on disk
I20260812 06:18:37.621632 32672 maintenance_manager.cc:643] P 2d465b03569440adadbe2672966db0c0: UndoDeltaBlockGCOp(4c164e5ecfcc4dc7ad217804776f500a) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4}
I20260812 06:18:37.622260   305 maintenance_manager.cc:419] P 2d465b03569440adadbe2672966db0c0: Scheduling MajorDeltaCompactionOp(4c164e5ecfcc4dc7ad217804776f500a): perf score=1.000000
I20260812 06:18:37.692754 32212 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.048s	user 1.854s	sys 0.182s
I20260812 06:18:37.767666 32212 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.074s	user 0.001s	sys 0.000s
I20260812 06:18:37.768217 32212 tablet_server.cc:179] TabletServer@127.31.117.1:0 shutting down...
I20260812 06:18:37.781831 32672 maintenance_manager.cc:643] P 2d465b03569440adadbe2672966db0c0: MajorDeltaCompactionOp(4c164e5ecfcc4dc7ad217804776f500a) complete. Timing: real 0.159s	user 0.101s	sys 0.056s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877212,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1059,"lbm_read_time_us":13167,"lbm_reads_lt_1ms":665,"lbm_write_time_us":29546,"lbm_writes_lt_1ms":643,"mutex_wait_us":22,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":23808,"thread_start_us":92,"threads_started":1,"update_count":3000}
I20260812 06:18:37.782873 32212 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:37.783100 32212 tablet_replica.cc:333] T 4c164e5ecfcc4dc7ad217804776f500a P 2d465b03569440adadbe2672966db0c0: stopping tablet replica
I20260812 06:18:37.783272 32212 raft_consensus.cc:2243] T 4c164e5ecfcc4dc7ad217804776f500a P 2d465b03569440adadbe2672966db0c0 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:37.783478 32212 raft_consensus.cc:2272] T 4c164e5ecfcc4dc7ad217804776f500a P 2d465b03569440adadbe2672966db0c0 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:37.799389 32212 tablet_server.cc:196] TabletServer@127.31.117.1:0 shutdown complete.
I20260812 06:18:37.830065 32212 master.cc:562] Master@127.31.117.62:42497 shutting down...
I20260812 06:18:37.833914 32212 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 9ce5f068b4164ba7a54d43e5d8218b1b [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:37.834131 32212 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 9ce5f068b4164ba7a54d43e5d8218b1b [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:37.834215 32212 tablet_replica.cc:333] T 00000000000000000000000000000000 P 9ce5f068b4164ba7a54d43e5d8218b1b: stopping tablet replica
I20260812 06:18:37.846668 32212 master.cc:584] Master@127.31.117.62:42497 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5517 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11224 ms total)

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