[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:19:52.867972  3463 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.3.97.254:39441
I20260812 06:19:52.868985  3463 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:19:52.869609  3463 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:52.876422  3469 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:52.876495  3463 server_base.cc:1061] running on GCE node
W20260812 06:19:52.876438  3470 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:52.876771  3472 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:52.877311  3463 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:52.877403  3463 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:52.877435  3463 hybrid_clock.cc:648] HybridClock initialized: now 1786515592877433 us; error 0 us; skew 500 ppm
I20260812 06:19:52.879473  3463 webserver.cc:533] Webserver started at http://127.3.97.254:38461/ using document root <none> and password file <none>
I20260812 06:19:52.880043  3463 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:52.880131  3463 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:52.880402  3463 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:52.882192  3463 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515592857258-3463-0/minicluster-data/master-0-root/instance:
uuid: "2b7cf0ec21a74ad1a9afd341831664c5"
format_stamp: "Formatted at 2026-08-12 06:19:52 on dist-test-slave-9gcw"
I20260812 06:19:52.885726  3463 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.002s	sys 0.002s
I20260812 06:19:52.887749  3477 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:52.888684  3463 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:52.888813  3463 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515592857258-3463-0/minicluster-data/master-0-root
uuid: "2b7cf0ec21a74ad1a9afd341831664c5"
format_stamp: "Formatted at 2026-08-12 06:19:52 on dist-test-slave-9gcw"
I20260812 06:19:52.888918  3463 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515592857258-3463-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515592857258-3463-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515592857258-3463-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:52.897989  3463 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:52.898589  3463 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:19:52.898772  3463 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:52.906927  3533 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.3.97.254:39441 every 8 connection(s)
I20260812 06:19:52.906929  3463 rpc_server.cc:307] RPC server started. Bound to: 127.3.97.254:39441
I20260812 06:19:52.909343  3534 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:52.914878  3534 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 2b7cf0ec21a74ad1a9afd341831664c5: Bootstrap starting.
I20260812 06:19:52.917372  3534 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 2b7cf0ec21a74ad1a9afd341831664c5: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:52.918236  3534 log.cc:826] T 00000000000000000000000000000000 P 2b7cf0ec21a74ad1a9afd341831664c5: Log is configured to *not* fsync() on all Append() calls
I20260812 06:19:52.919893  3534 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 2b7cf0ec21a74ad1a9afd341831664c5: No bootstrap required, opened a new log
I20260812 06:19:52.922670  3534 raft_consensus.cc:359] T 00000000000000000000000000000000 P 2b7cf0ec21a74ad1a9afd341831664c5 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2b7cf0ec21a74ad1a9afd341831664c5" member_type: VOTER }
I20260812 06:19:52.922896  3534 raft_consensus.cc:385] T 00000000000000000000000000000000 P 2b7cf0ec21a74ad1a9afd341831664c5 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:52.922977  3534 raft_consensus.cc:740] T 00000000000000000000000000000000 P 2b7cf0ec21a74ad1a9afd341831664c5 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 2b7cf0ec21a74ad1a9afd341831664c5, State: Initialized, Role: FOLLOWER
I20260812 06:19:52.923825  3534 consensus_queue.cc:260] T 00000000000000000000000000000000 P 2b7cf0ec21a74ad1a9afd341831664c5 [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: "2b7cf0ec21a74ad1a9afd341831664c5" member_type: VOTER }
I20260812 06:19:52.924031  3534 raft_consensus.cc:399] T 00000000000000000000000000000000 P 2b7cf0ec21a74ad1a9afd341831664c5 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:52.924114  3534 raft_consensus.cc:493] T 00000000000000000000000000000000 P 2b7cf0ec21a74ad1a9afd341831664c5 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:52.924252  3534 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 2b7cf0ec21a74ad1a9afd341831664c5 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:52.925513  3534 raft_consensus.cc:515] T 00000000000000000000000000000000 P 2b7cf0ec21a74ad1a9afd341831664c5 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2b7cf0ec21a74ad1a9afd341831664c5" member_type: VOTER }
I20260812 06:19:52.926048  3534 leader_election.cc:304] T 00000000000000000000000000000000 P 2b7cf0ec21a74ad1a9afd341831664c5 [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: 2b7cf0ec21a74ad1a9afd341831664c5; no voters: 
I20260812 06:19:52.926455  3534 leader_election.cc:290] T 00000000000000000000000000000000 P 2b7cf0ec21a74ad1a9afd341831664c5 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:52.926621  3538 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 2b7cf0ec21a74ad1a9afd341831664c5 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:52.926941  3538 raft_consensus.cc:697] T 00000000000000000000000000000000 P 2b7cf0ec21a74ad1a9afd341831664c5 [term 1 LEADER]: Becoming Leader. State: Replica: 2b7cf0ec21a74ad1a9afd341831664c5, State: Running, Role: LEADER
I20260812 06:19:52.927484  3538 consensus_queue.cc:237] T 00000000000000000000000000000000 P 2b7cf0ec21a74ad1a9afd341831664c5 [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: "2b7cf0ec21a74ad1a9afd341831664c5" member_type: VOTER }
I20260812 06:19:52.927623  3534 sys_catalog.cc:565] T 00000000000000000000000000000000 P 2b7cf0ec21a74ad1a9afd341831664c5 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:52.929593  3541 sys_catalog.cc:455] T 00000000000000000000000000000000 P 2b7cf0ec21a74ad1a9afd341831664c5 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "2b7cf0ec21a74ad1a9afd341831664c5" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2b7cf0ec21a74ad1a9afd341831664c5" member_type: VOTER } }
I20260812 06:19:52.929723  3541 sys_catalog.cc:458] T 00000000000000000000000000000000 P 2b7cf0ec21a74ad1a9afd341831664c5 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:52.930171  3539 sys_catalog.cc:455] T 00000000000000000000000000000000 P 2b7cf0ec21a74ad1a9afd341831664c5 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 2b7cf0ec21a74ad1a9afd341831664c5. Latest consensus state: current_term: 1 leader_uuid: "2b7cf0ec21a74ad1a9afd341831664c5" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2b7cf0ec21a74ad1a9afd341831664c5" member_type: VOTER } }
I20260812 06:19:52.930284  3539 sys_catalog.cc:458] T 00000000000000000000000000000000 P 2b7cf0ec21a74ad1a9afd341831664c5 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:52.930379  3463 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:52.930558  3553 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:52.933053  3553 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:52.937898  3553 catalog_manager.cc:1383] Generated new cluster ID: 5fc46d5eafff4f57b0930ee9c5dc6d78
I20260812 06:19:52.937965  3553 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:52.965497  3553 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:52.966493  3553 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:52.971596  3553 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 2b7cf0ec21a74ad1a9afd341831664c5: Generated new TSK 0
I20260812 06:19:52.972208  3553 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:52.995044  3463 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:52.997962  3563 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:52.998015  3566 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:52.998107  3463 server_base.cc:1061] running on GCE node
W20260812 06:19:52.998128  3564 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:52.998379  3463 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:52.998441  3463 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:52.998471  3463 hybrid_clock.cc:648] HybridClock initialized: now 1786515592998468 us; error 0 us; skew 500 ppm
I20260812 06:19:52.999449  3463 webserver.cc:533] Webserver started at http://127.3.97.193:44911/ using document root <none> and password file <none>
I20260812 06:19:52.999626  3463 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:52.999693  3463 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:52.999773  3463 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:53.000175  3463 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515592857258-3463-0/minicluster-data/ts-0-root/instance:
uuid: "af438b57668145879591e0bb4e892851"
format_stamp: "Formatted at 2026-08-12 06:19:52 on dist-test-slave-9gcw"
I20260812 06:19:53.001806  3463 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:53.002780  3572 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:53.003028  3463 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:53.003098  3463 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515592857258-3463-0/minicluster-data/ts-0-root
uuid: "af438b57668145879591e0bb4e892851"
format_stamp: "Formatted at 2026-08-12 06:19:52 on dist-test-slave-9gcw"
I20260812 06:19:53.003180  3463 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515592857258-3463-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515592857258-3463-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515592857258-3463-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:53.015834  3463 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:53.016287  3463 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:53.016789  3463 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:53.017712  3463 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:53.017767  3463 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:53.017832  3463 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:53.017868  3463 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:53.024889  3463 rpc_server.cc:307] RPC server started. Bound to: 127.3.97.193:46201
I20260812 06:19:53.024922  3645 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.3.97.193:46201 every 8 connection(s)
I20260812 06:19:53.035027  3646 heartbeater.cc:344] Connected to a master server at 127.3.97.254:39441
I20260812 06:19:53.035292  3646 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:53.035737  3646 heartbeater.cc:507] Master 127.3.97.254:39441 requested a full tablet report, sending...
I20260812 06:19:53.037199  3494 ts_manager.cc:194] Registered new tserver with Master: af438b57668145879591e0bb4e892851 (127.3.97.193:46201)
I20260812 06:19:53.038101  3463 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.012523041s
I20260812 06:19:53.038461  3494 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:54284
I20260812 06:19:53.047384  3494 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:54292:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:19:53.062011  3603 tablet_service.cc:1511] Processing CreateTablet for tablet ba7acad5a9564ea799667d7385684563 (DEFAULT_TABLE table=heavy-update-compaction-test [id=50a384f4c1c04b91a57355e5f1c15a95]), partition=
I20260812 06:19:53.062470  3603 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet ba7acad5a9564ea799667d7385684563. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:53.065342  3660 tablet_bootstrap.cc:492] T ba7acad5a9564ea799667d7385684563 P af438b57668145879591e0bb4e892851: Bootstrap starting.
I20260812 06:19:53.066294  3660 tablet_bootstrap.cc:654] T ba7acad5a9564ea799667d7385684563 P af438b57668145879591e0bb4e892851: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:53.067395  3660 tablet_bootstrap.cc:492] T ba7acad5a9564ea799667d7385684563 P af438b57668145879591e0bb4e892851: No bootstrap required, opened a new log
I20260812 06:19:53.067480  3660 ts_tablet_manager.cc:1403] T ba7acad5a9564ea799667d7385684563 P af438b57668145879591e0bb4e892851: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:53.067965  3660 raft_consensus.cc:359] T ba7acad5a9564ea799667d7385684563 P af438b57668145879591e0bb4e892851 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "af438b57668145879591e0bb4e892851" member_type: VOTER last_known_addr { host: "127.3.97.193" port: 46201 } }
I20260812 06:19:53.068065  3660 raft_consensus.cc:385] T ba7acad5a9564ea799667d7385684563 P af438b57668145879591e0bb4e892851 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:53.068089  3660 raft_consensus.cc:740] T ba7acad5a9564ea799667d7385684563 P af438b57668145879591e0bb4e892851 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: af438b57668145879591e0bb4e892851, State: Initialized, Role: FOLLOWER
I20260812 06:19:53.068286  3660 consensus_queue.cc:260] T ba7acad5a9564ea799667d7385684563 P af438b57668145879591e0bb4e892851 [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: "af438b57668145879591e0bb4e892851" member_type: VOTER last_known_addr { host: "127.3.97.193" port: 46201 } }
I20260812 06:19:53.068361  3660 raft_consensus.cc:399] T ba7acad5a9564ea799667d7385684563 P af438b57668145879591e0bb4e892851 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:53.068387  3660 raft_consensus.cc:493] T ba7acad5a9564ea799667d7385684563 P af438b57668145879591e0bb4e892851 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:53.068460  3660 raft_consensus.cc:3060] T ba7acad5a9564ea799667d7385684563 P af438b57668145879591e0bb4e892851 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:53.069362  3660 raft_consensus.cc:515] T ba7acad5a9564ea799667d7385684563 P af438b57668145879591e0bb4e892851 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "af438b57668145879591e0bb4e892851" member_type: VOTER last_known_addr { host: "127.3.97.193" port: 46201 } }
I20260812 06:19:53.069527  3660 leader_election.cc:304] T ba7acad5a9564ea799667d7385684563 P af438b57668145879591e0bb4e892851 [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: af438b57668145879591e0bb4e892851; no voters: 
I20260812 06:19:53.069757  3660 leader_election.cc:290] T ba7acad5a9564ea799667d7385684563 P af438b57668145879591e0bb4e892851 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:53.069857  3662 raft_consensus.cc:2804] T ba7acad5a9564ea799667d7385684563 P af438b57668145879591e0bb4e892851 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:53.070044  3662 raft_consensus.cc:697] T ba7acad5a9564ea799667d7385684563 P af438b57668145879591e0bb4e892851 [term 1 LEADER]: Becoming Leader. State: Replica: af438b57668145879591e0bb4e892851, State: Running, Role: LEADER
I20260812 06:19:53.070115  3660 ts_tablet_manager.cc:1434] T ba7acad5a9564ea799667d7385684563 P af438b57668145879591e0bb4e892851: Time spent starting tablet: real 0.003s	user 0.000s	sys 0.003s
I20260812 06:19:53.070402  3646 heartbeater.cc:499] Master 127.3.97.254:39441 was elected leader, sending a full tablet report...
I20260812 06:19:53.070259  3662 consensus_queue.cc:237] T ba7acad5a9564ea799667d7385684563 P af438b57668145879591e0bb4e892851 [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: "af438b57668145879591e0bb4e892851" member_type: VOTER last_known_addr { host: "127.3.97.193" port: 46201 } }
I20260812 06:19:53.073230  3494 catalog_manager.cc:5719] T ba7acad5a9564ea799667d7385684563 P af438b57668145879591e0bb4e892851 reported cstate change: term changed from 0 to 1, leader changed from <none> to af438b57668145879591e0bb4e892851 (127.3.97.193). New cstate: current_term: 1 leader_uuid: "af438b57668145879591e0bb4e892851" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "af438b57668145879591e0bb4e892851" member_type: VOTER last_known_addr { host: "127.3.97.193" port: 46201 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:53.143573  3463 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.061s	user 0.028s	sys 0.004s
I20260812 06:19:53.275986  3647 maintenance_manager.cc:419] P af438b57668145879591e0bb4e892851: Scheduling FlushMRSOp(ba7acad5a9564ea799667d7385684563): perf score=19.054940
I20260812 06:19:53.427759  3578 maintenance_manager.cc:643] P af438b57668145879591e0bb4e892851: FlushMRSOp(ba7acad5a9564ea799667d7385684563) complete. Timing: real 0.151s	user 0.124s	sys 0.024s Metrics: {"bytes_written":8861468,"cfile_init":1,"compiler_manager_pool.queue_time_us":223,"delete_count":0,"dirs.queue_time_us":984,"dirs.run_cpu_time_us":182,"dirs.run_wall_time_us":825,"drs_written":1,"lbm_read_time_us":79,"lbm_reads_lt_1ms":4,"lbm_write_time_us":36653,"lbm_writes_lt_1ms":673,"mutex_wait_us":210,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":247040,"thread_start_us":148,"threads_started":1,"update_count":1080}
I20260812 06:19:53.428985  3647 maintenance_manager.cc:419] P af438b57668145879591e0bb4e892851: Scheduling LogGCOp(ba7acad5a9564ea799667d7385684563): free 20743880 bytes of WAL
I20260812 06:19:53.429316  3578 log_reader.cc:385] T ba7acad5a9564ea799667d7385684563: removed 2 log segments from log reader
I20260812 06:19:53.429387  3578 log.cc:1079] T ba7acad5a9564ea799667d7385684563 P af438b57668145879591e0bb4e892851: Deleting log segment in path: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515592857258-3463-0/minicluster-data/ts-0-root/wals/ba7acad5a9564ea799667d7385684563/wal-000000001 (ops 1-6)
I20260812 06:19:53.429442  3578 log.cc:1079] T ba7acad5a9564ea799667d7385684563 P af438b57668145879591e0bb4e892851: Deleting log segment in path: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515592857258-3463-0/minicluster-data/ts-0-root/wals/ba7acad5a9564ea799667d7385684563/wal-000000002 (ops 7-11)
I20260812 06:19:53.434859  3578 maintenance_manager.cc:643] P af438b57668145879591e0bb4e892851: LogGCOp(ba7acad5a9564ea799667d7385684563) complete. Timing: real 0.006s	user 0.001s	sys 0.003s Metrics: {}
I20260812 06:19:53.435287  3647 maintenance_manager.cc:419] P af438b57668145879591e0bb4e892851: Scheduling UndoDeltaBlockGCOp(ba7acad5a9564ea799667d7385684563): 16411393 bytes on disk
I20260812 06:19:53.435956  3578 maintenance_manager.cc:643] P af438b57668145879591e0bb4e892851: UndoDeltaBlockGCOp(ba7acad5a9564ea799667d7385684563) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4}
I20260812 06:19:53.436502  3647 maintenance_manager.cc:419] P af438b57668145879591e0bb4e892851: Scheduling FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563): perf score=2.188937
I20260812 06:19:53.454216  3578 maintenance_manager.cc:643] P af438b57668145879591e0bb4e892851: FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563) complete. Timing: real 0.018s	user 0.006s	sys 0.003s Metrics: {"bytes_written":3446255,"delete_count":0,"lbm_write_time_us":3944,"lbm_writes_lt_1ms":87,"reinsert_count":0,"update_count":420}
I20260812 06:19:53.454797  3647 maintenance_manager.cc:419] P af438b57668145879591e0bb4e892851: Scheduling FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563): perf score=2.188937
I20260812 06:19:53.468936  3578 maintenance_manager.cc:643] P af438b57668145879591e0bb4e892851: FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563) complete. Timing: real 0.014s	user 0.004s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5522,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:53.469419  3647 maintenance_manager.cc:419] P af438b57668145879591e0bb4e892851: Scheduling MajorDeltaCompactionOp(ba7acad5a9564ea799667d7385684563): perf score=1.000000
I20260812 06:19:53.616415  3578 maintenance_manager.cc:643] P af438b57668145879591e0bb4e892851: MajorDeltaCompactionOp(ba7acad5a9564ea799667d7385684563) complete. Timing: real 0.147s	user 0.111s	sys 0.027s Metrics: {"cfile_cache_miss":433,"cfile_cache_miss_bytes":20672382,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":886,"lbm_read_time_us":8879,"lbm_reads_lt_1ms":469,"lbm_write_time_us":25129,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"thread_start_us":352,"threads_started":5,"update_count":2000}
I20260812 06:19:53.617053  3647 maintenance_manager.cc:419] P af438b57668145879591e0bb4e892851: Scheduling FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563): perf score=10.126437
I20260812 06:19:53.667384  3578 maintenance_manager.cc:643] P af438b57668145879591e0bb4e892851: FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563) complete. Timing: real 0.050s	user 0.020s	sys 0.015s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":16490,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:53.668025  3647 maintenance_manager.cc:419] P af438b57668145879591e0bb4e892851: Scheduling FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563): perf score=2.188937
I20260812 06:19:53.683892  3578 maintenance_manager.cc:643] P af438b57668145879591e0bb4e892851: FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563) complete. Timing: real 0.016s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5836,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:53.684499  3647 maintenance_manager.cc:419] P af438b57668145879591e0bb4e892851: Scheduling MajorDeltaCompactionOp(ba7acad5a9564ea799667d7385684563): perf score=1.000000
I20260812 06:19:53.816283  3578 maintenance_manager.cc:643] P af438b57668145879591e0bb4e892851: MajorDeltaCompactionOp(ba7acad5a9564ea799667d7385684563) complete. Timing: real 0.132s	user 0.127s	sys 0.004s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":223,"lbm_read_time_us":9354,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24334,"lbm_writes_lt_1ms":443,"mutex_wait_us":39,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":20736,"update_count":2000}
I20260812 06:19:53.816911  3647 maintenance_manager.cc:419] P af438b57668145879591e0bb4e892851: Scheduling FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563): perf score=10.126437
I20260812 06:19:53.862353  3578 maintenance_manager.cc:643] P af438b57668145879591e0bb4e892851: FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563) complete. Timing: real 0.045s	user 0.022s	sys 0.016s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":17296,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:53.862814  3647 maintenance_manager.cc:419] P af438b57668145879591e0bb4e892851: Scheduling FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563): perf score=2.188937
I20260812 06:19:53.873520  3578 maintenance_manager.cc:643] P af438b57668145879591e0bb4e892851: FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4006,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:53.874275  3647 maintenance_manager.cc:419] P af438b57668145879591e0bb4e892851: Scheduling MajorDeltaCompactionOp(ba7acad5a9564ea799667d7385684563): perf score=1.000000
I20260812 06:19:54.004933  3578 maintenance_manager.cc:643] P af438b57668145879591e0bb4e892851: MajorDeltaCompactionOp(ba7acad5a9564ea799667d7385684563) complete. Timing: real 0.130s	user 0.092s	sys 0.037s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672280,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":719,"lbm_read_time_us":9603,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24828,"lbm_writes_lt_1ms":443,"mutex_wait_us":86,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7936,"update_count":2000}
I20260812 06:19:54.005542  3647 maintenance_manager.cc:419] P af438b57668145879591e0bb4e892851: Scheduling FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563): perf score=10.126437
I20260812 06:19:54.059156  3578 maintenance_manager.cc:643] P af438b57668145879591e0bb4e892851: FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563) complete. Timing: real 0.053s	user 0.023s	sys 0.023s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16700,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:54.059707  3647 maintenance_manager.cc:419] P af438b57668145879591e0bb4e892851: Scheduling FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563): perf score=2.188937
I20260812 06:19:54.070448  3578 maintenance_manager.cc:643] P af438b57668145879591e0bb4e892851: FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4152,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:54.070914  3647 maintenance_manager.cc:419] P af438b57668145879591e0bb4e892851: Scheduling MajorDeltaCompactionOp(ba7acad5a9564ea799667d7385684563): perf score=1.000000
I20260812 06:19:54.227279  3578 maintenance_manager.cc:643] P af438b57668145879591e0bb4e892851: MajorDeltaCompactionOp(ba7acad5a9564ea799667d7385684563) complete. Timing: real 0.156s	user 0.102s	sys 0.047s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":633,"lbm_read_time_us":10927,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26653,"lbm_writes_lt_1ms":443,"mutex_wait_us":273,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5632,"update_count":2000}
I20260812 06:19:54.227831  3647 maintenance_manager.cc:419] P af438b57668145879591e0bb4e892851: Scheduling FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563): perf score=10.126437
I20260812 06:19:54.280320  3578 maintenance_manager.cc:643] P af438b57668145879591e0bb4e892851: FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563) complete. Timing: real 0.052s	user 0.024s	sys 0.016s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":18741,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:54.280833  3647 maintenance_manager.cc:419] P af438b57668145879591e0bb4e892851: Scheduling FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563): perf score=2.188937
I20260812 06:19:54.291039  3578 maintenance_manager.cc:643] P af438b57668145879591e0bb4e892851: FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563) complete. Timing: real 0.010s	user 0.005s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3836,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:54.291494  3647 maintenance_manager.cc:419] P af438b57668145879591e0bb4e892851: Scheduling MajorDeltaCompactionOp(ba7acad5a9564ea799667d7385684563): perf score=1.000000
I20260812 06:19:54.420517  3578 maintenance_manager.cc:643] P af438b57668145879591e0bb4e892851: MajorDeltaCompactionOp(ba7acad5a9564ea799667d7385684563) complete. Timing: real 0.129s	user 0.102s	sys 0.025s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":379,"lbm_read_time_us":9497,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23737,"lbm_writes_lt_1ms":443,"mutex_wait_us":65,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8704,"update_count":2000}
I20260812 06:19:54.421080  3647 maintenance_manager.cc:419] P af438b57668145879591e0bb4e892851: Scheduling FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563): perf score=10.126437
I20260812 06:19:54.467554  3578 maintenance_manager.cc:643] P af438b57668145879591e0bb4e892851: FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563) complete. Timing: real 0.046s	user 0.030s	sys 0.004s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15624,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:54.468040  3647 maintenance_manager.cc:419] P af438b57668145879591e0bb4e892851: Scheduling FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563): perf score=2.188937
I20260812 06:19:54.479213  3578 maintenance_manager.cc:643] P af438b57668145879591e0bb4e892851: FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4102,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:54.479872  3647 maintenance_manager.cc:419] P af438b57668145879591e0bb4e892851: Scheduling MajorDeltaCompactionOp(ba7acad5a9564ea799667d7385684563): perf score=1.000000
I20260812 06:19:54.602980  3578 maintenance_manager.cc:643] P af438b57668145879591e0bb4e892851: MajorDeltaCompactionOp(ba7acad5a9564ea799667d7385684563) complete. Timing: real 0.123s	user 0.093s	sys 0.029s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":328,"lbm_read_time_us":8865,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22947,"lbm_writes_lt_1ms":443,"mutex_wait_us":74,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1152,"update_count":2000}
I20260812 06:19:54.603547  3647 maintenance_manager.cc:419] P af438b57668145879591e0bb4e892851: Scheduling FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563): perf score=10.126437
I20260812 06:19:54.648000  3578 maintenance_manager.cc:643] P af438b57668145879591e0bb4e892851: FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563) complete. Timing: real 0.044s	user 0.023s	sys 0.018s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":16650,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:54.648507  3647 maintenance_manager.cc:419] P af438b57668145879591e0bb4e892851: Scheduling FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563): perf score=2.188937
I20260812 06:19:54.658990  3578 maintenance_manager.cc:643] P af438b57668145879591e0bb4e892851: FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4067,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:54.659421  3647 maintenance_manager.cc:419] P af438b57668145879591e0bb4e892851: Scheduling FlushMRSOp(ba7acad5a9564ea799667d7385684563): perf score=1.000000
I20260812 06:19:54.702277  3578 maintenance_manager.cc:643] P af438b57668145879591e0bb4e892851: FlushMRSOp(ba7acad5a9564ea799667d7385684563) complete. Timing: real 0.043s	user 0.029s	sys 0.001s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":72,"dirs.run_cpu_time_us":256,"dirs.run_wall_time_us":1794,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1423,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:19:54.703054  3647 maintenance_manager.cc:419] P af438b57668145879591e0bb4e892851: Scheduling LogGCOp(ba7acad5a9564ea799667d7385684563): free 115943177 bytes of WAL
I20260812 06:19:54.703289  3578 log_reader.cc:385] T ba7acad5a9564ea799667d7385684563: removed 11 log segments from log reader
I20260812 06:19:54.703352  3578 log.cc:1079] T ba7acad5a9564ea799667d7385684563 P af438b57668145879591e0bb4e892851: Deleting log segment in path: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515592857258-3463-0/minicluster-data/ts-0-root/wals/ba7acad5a9564ea799667d7385684563/wal-000000003 (ops 12-16)
I20260812 06:19:54.703404  3578 log.cc:1079] T ba7acad5a9564ea799667d7385684563 P af438b57668145879591e0bb4e892851: Deleting log segment in path: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515592857258-3463-0/minicluster-data/ts-0-root/wals/ba7acad5a9564ea799667d7385684563/wal-000000004 (ops 17-21)
I20260812 06:19:54.703462  3578 log.cc:1079] T ba7acad5a9564ea799667d7385684563 P af438b57668145879591e0bb4e892851: Deleting log segment in path: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515592857258-3463-0/minicluster-data/ts-0-root/wals/ba7acad5a9564ea799667d7385684563/wal-000000005 (ops 22-26)
I20260812 06:19:54.703503  3578 log.cc:1079] T ba7acad5a9564ea799667d7385684563 P af438b57668145879591e0bb4e892851: Deleting log segment in path: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515592857258-3463-0/minicluster-data/ts-0-root/wals/ba7acad5a9564ea799667d7385684563/wal-000000006 (ops 27-31)
I20260812 06:19:54.703555  3578 log.cc:1079] T ba7acad5a9564ea799667d7385684563 P af438b57668145879591e0bb4e892851: Deleting log segment in path: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515592857258-3463-0/minicluster-data/ts-0-root/wals/ba7acad5a9564ea799667d7385684563/wal-000000007 (ops 32-36)
I20260812 06:19:54.703594  3578 log.cc:1079] T ba7acad5a9564ea799667d7385684563 P af438b57668145879591e0bb4e892851: Deleting log segment in path: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515592857258-3463-0/minicluster-data/ts-0-root/wals/ba7acad5a9564ea799667d7385684563/wal-000000008 (ops 37-41)
I20260812 06:19:54.703629  3578 log.cc:1079] T ba7acad5a9564ea799667d7385684563 P af438b57668145879591e0bb4e892851: Deleting log segment in path: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515592857258-3463-0/minicluster-data/ts-0-root/wals/ba7acad5a9564ea799667d7385684563/wal-000000009 (ops 42-46)
I20260812 06:19:54.703668  3578 log.cc:1079] T ba7acad5a9564ea799667d7385684563 P af438b57668145879591e0bb4e892851: Deleting log segment in path: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515592857258-3463-0/minicluster-data/ts-0-root/wals/ba7acad5a9564ea799667d7385684563/wal-000000010 (ops 47-51)
I20260812 06:19:54.703706  3578 log.cc:1079] T ba7acad5a9564ea799667d7385684563 P af438b57668145879591e0bb4e892851: Deleting log segment in path: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515592857258-3463-0/minicluster-data/ts-0-root/wals/ba7acad5a9564ea799667d7385684563/wal-000000011 (ops 52-56)
I20260812 06:19:54.703742  3578 log.cc:1079] T ba7acad5a9564ea799667d7385684563 P af438b57668145879591e0bb4e892851: Deleting log segment in path: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515592857258-3463-0/minicluster-data/ts-0-root/wals/ba7acad5a9564ea799667d7385684563/wal-000000012 (ops 57-61)
I20260812 06:19:54.703778  3578 log.cc:1079] T ba7acad5a9564ea799667d7385684563 P af438b57668145879591e0bb4e892851: Deleting log segment in path: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515592857258-3463-0/minicluster-data/ts-0-root/wals/ba7acad5a9564ea799667d7385684563/wal-000000013 (ops 62-66)
I20260812 06:19:54.727783  3578 maintenance_manager.cc:643] P af438b57668145879591e0bb4e892851: LogGCOp(ba7acad5a9564ea799667d7385684563) complete. Timing: real 0.025s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:19:54.728235  3647 maintenance_manager.cc:419] P af438b57668145879591e0bb4e892851: Scheduling UndoDeltaBlockGCOp(ba7acad5a9564ea799667d7385684563): 447 bytes on disk
I20260812 06:19:54.728947  3578 maintenance_manager.cc:643] P af438b57668145879591e0bb4e892851: UndoDeltaBlockGCOp(ba7acad5a9564ea799667d7385684563) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":106,"lbm_reads_lt_1ms":4}
I20260812 06:19:54.729627  3647 maintenance_manager.cc:419] P af438b57668145879591e0bb4e892851: Scheduling FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563): perf score=2.188937
I20260812 06:19:54.745824  3578 maintenance_manager.cc:643] P af438b57668145879591e0bb4e892851: FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563) complete. Timing: real 0.016s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4105,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:54.746299  3647 maintenance_manager.cc:419] P af438b57668145879591e0bb4e892851: Scheduling FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563): perf score=2.188937
I20260812 06:19:54.756419  3578 maintenance_manager.cc:643] P af438b57668145879591e0bb4e892851: FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3858,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:54.756940  3647 maintenance_manager.cc:419] P af438b57668145879591e0bb4e892851: Scheduling MajorDeltaCompactionOp(ba7acad5a9564ea799667d7385684563): perf score=1.000000
I20260812 06:19:54.966562  3578 maintenance_manager.cc:643] P af438b57668145879591e0bb4e892851: MajorDeltaCompactionOp(ba7acad5a9564ea799667d7385684563) complete. Timing: real 0.209s	user 0.142s	sys 0.067s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877338,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":746,"lbm_read_time_us":12717,"lbm_reads_lt_1ms":674,"lbm_write_time_us":35258,"lbm_writes_lt_1ms":643,"mutex_wait_us":410,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":26880,"thread_start_us":82,"threads_started":1,"update_count":3000}
I20260812 06:19:54.967126  3647 maintenance_manager.cc:419] P af438b57668145879591e0bb4e892851: Scheduling FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563): perf score=14.095187
I20260812 06:19:55.036166  3578 maintenance_manager.cc:643] P af438b57668145879591e0bb4e892851: FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563) complete. Timing: real 0.069s	user 0.025s	sys 0.028s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":25354,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:55.036806  3647 maintenance_manager.cc:419] P af438b57668145879591e0bb4e892851: Scheduling FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563): perf score=2.188937
I20260812 06:19:55.047430  3578 maintenance_manager.cc:643] P af438b57668145879591e0bb4e892851: FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563) complete. Timing: real 0.010s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4059,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:55.048053  3647 maintenance_manager.cc:419] P af438b57668145879591e0bb4e892851: Scheduling MajorDeltaCompactionOp(ba7acad5a9564ea799667d7385684563): perf score=1.000000
I20260812 06:19:55.225319  3578 maintenance_manager.cc:643] P af438b57668145879591e0bb4e892851: MajorDeltaCompactionOp(ba7acad5a9564ea799667d7385684563) complete. Timing: real 0.177s	user 0.117s	sys 0.048s 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":781,"lbm_read_time_us":12736,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28592,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8064,"update_count":2500}
I20260812 06:19:55.225857  3647 maintenance_manager.cc:419] P af438b57668145879591e0bb4e892851: Scheduling FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563): perf score=14.095187
I20260812 06:19:55.296341  3578 maintenance_manager.cc:643] P af438b57668145879591e0bb4e892851: FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563) complete. Timing: real 0.070s	user 0.035s	sys 0.032s Metrics: {"bytes_written":16409906,"delete_count":0,"lbm_write_time_us":30184,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":400,"reinsert_count":0,"update_count":2000}
I20260812 06:19:55.296968  3647 maintenance_manager.cc:419] P af438b57668145879591e0bb4e892851: Scheduling FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563): perf score=2.188937
I20260812 06:19:55.308404  3578 maintenance_manager.cc:643] P af438b57668145879591e0bb4e892851: FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4311,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:55.309121  3647 maintenance_manager.cc:419] P af438b57668145879591e0bb4e892851: Scheduling MajorDeltaCompactionOp(ba7acad5a9564ea799667d7385684563): perf score=1.000000
I20260812 06:19:55.478359  3578 maintenance_manager.cc:643] P af438b57668145879591e0bb4e892851: MajorDeltaCompactionOp(ba7acad5a9564ea799667d7385684563) complete. Timing: real 0.169s	user 0.109s	sys 0.057s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774693,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":952,"lbm_read_time_us":12451,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29492,"lbm_writes_lt_1ms":543,"mutex_wait_us":52,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8320,"update_count":2500}
I20260812 06:19:55.479010  3647 maintenance_manager.cc:419] P af438b57668145879591e0bb4e892851: Scheduling FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563): perf score=11.118625
I20260812 06:19:55.514643  3578 maintenance_manager.cc:643] P af438b57668145879591e0bb4e892851: FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563) complete. Timing: real 0.035s	user 0.031s	sys 0.003s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":15078,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:55.515322  3647 maintenance_manager.cc:419] P af438b57668145879591e0bb4e892851: Scheduling FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563): perf score=2.188937
I20260812 06:19:55.538488  3578 maintenance_manager.cc:643] P af438b57668145879591e0bb4e892851: FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563) complete. Timing: real 0.023s	user 0.008s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5247,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:55.539058  3647 maintenance_manager.cc:419] P af438b57668145879591e0bb4e892851: Scheduling MajorDeltaCompactionOp(ba7acad5a9564ea799667d7385684563): perf score=1.000000
I20260812 06:19:55.687323  3578 maintenance_manager.cc:643] P af438b57668145879591e0bb4e892851: MajorDeltaCompactionOp(ba7acad5a9564ea799667d7385684563) complete. Timing: real 0.148s	user 0.092s	sys 0.045s 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":895,"lbm_read_time_us":8308,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24863,"lbm_writes_lt_1ms":443,"mutex_wait_us":280,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:55.687916  3647 maintenance_manager.cc:419] P af438b57668145879591e0bb4e892851: Scheduling FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563): perf score=14.095187
I20260812 06:19:55.747598  3578 maintenance_manager.cc:643] P af438b57668145879591e0bb4e892851: FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563) complete. Timing: real 0.060s	user 0.032s	sys 0.025s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":27703,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:19:55.748116  3647 maintenance_manager.cc:419] P af438b57668145879591e0bb4e892851: Scheduling FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563): perf score=2.188937
I20260812 06:19:55.759181  3578 maintenance_manager.cc:643] P af438b57668145879591e0bb4e892851: FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3918,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:55.759654  3647 maintenance_manager.cc:419] P af438b57668145879591e0bb4e892851: Scheduling MajorDeltaCompactionOp(ba7acad5a9564ea799667d7385684563): perf score=1.000000
I20260812 06:19:55.911980  3578 maintenance_manager.cc:643] P af438b57668145879591e0bb4e892851: MajorDeltaCompactionOp(ba7acad5a9564ea799667d7385684563) complete. Timing: real 0.152s	user 0.113s	sys 0.036s 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":981,"lbm_read_time_us":10828,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29498,"lbm_writes_lt_1ms":543,"mutex_wait_us":142,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":15616,"update_count":2500}
I20260812 06:19:55.912832  3647 maintenance_manager.cc:419] P af438b57668145879591e0bb4e892851: Scheduling FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563): perf score=11.118625
I20260812 06:19:55.960124  3578 maintenance_manager.cc:643] P af438b57668145879591e0bb4e892851: FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563) complete. Timing: real 0.047s	user 0.021s	sys 0.021s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":19229,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:55.960896  3647 maintenance_manager.cc:419] P af438b57668145879591e0bb4e892851: Scheduling FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563): perf score=2.188937
I20260812 06:19:55.975533  3578 maintenance_manager.cc:643] P af438b57668145879591e0bb4e892851: FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563) complete. Timing: real 0.014s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3841,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:55.976022  3647 maintenance_manager.cc:419] P af438b57668145879591e0bb4e892851: Scheduling FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563): perf score=2.188937
I20260812 06:19:55.985973  3578 maintenance_manager.cc:643] P af438b57668145879591e0bb4e892851: FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3710,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:55.986430  3647 maintenance_manager.cc:419] P af438b57668145879591e0bb4e892851: Scheduling MajorDeltaCompactionOp(ba7acad5a9564ea799667d7385684563): perf score=1.000000
I20260812 06:19:56.152889  3578 maintenance_manager.cc:643] P af438b57668145879591e0bb4e892851: MajorDeltaCompactionOp(ba7acad5a9564ea799667d7385684563) complete. Timing: real 0.166s	user 0.132s	sys 0.034s 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":148,"lbm_read_time_us":11398,"lbm_reads_lt_1ms":573,"lbm_write_time_us":35772,"lbm_writes_lt_1ms":543,"mutex_wait_us":29,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12544,"update_count":2500}
I20260812 06:19:56.154147  3647 maintenance_manager.cc:419] P af438b57668145879591e0bb4e892851: Scheduling FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563): perf score=10.126437
I20260812 06:19:56.194446  3578 maintenance_manager.cc:643] P af438b57668145879591e0bb4e892851: FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563) complete. Timing: real 0.040s	user 0.026s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16570,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:56.195001  3647 maintenance_manager.cc:419] P af438b57668145879591e0bb4e892851: Scheduling FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563): perf score=2.188937
I20260812 06:19:56.209601  3578 maintenance_manager.cc:643] P af438b57668145879591e0bb4e892851: FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563) complete. Timing: real 0.014s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5662,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:56.210140  3647 maintenance_manager.cc:419] P af438b57668145879591e0bb4e892851: Scheduling FlushMRSOp(ba7acad5a9564ea799667d7385684563): perf score=1.000000
I20260812 06:19:56.240510  3578 maintenance_manager.cc:643] P af438b57668145879591e0bb4e892851: FlushMRSOp(ba7acad5a9564ea799667d7385684563) complete. Timing: real 0.030s	user 0.028s	sys 0.000s Metrics: {"bytes_written":1234479,"cfile_init":1,"dirs.queue_time_us":77,"dirs.run_cpu_time_us":235,"dirs.run_wall_time_us":1345,"drs_written":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1608,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:19:56.241354  3647 maintenance_manager.cc:419] P af438b57668145879591e0bb4e892851: Scheduling LogGCOp(ba7acad5a9564ea799667d7385684563): free 121006432 bytes of WAL
I20260812 06:19:56.241604  3578 log_reader.cc:385] T ba7acad5a9564ea799667d7385684563: removed 12 log segments from log reader
I20260812 06:19:56.241673  3578 log.cc:1079] T ba7acad5a9564ea799667d7385684563 P af438b57668145879591e0bb4e892851: Deleting log segment in path: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515592857258-3463-0/minicluster-data/ts-0-root/wals/ba7acad5a9564ea799667d7385684563/wal-000000014 (ops 67-71)
I20260812 06:19:56.241724  3578 log.cc:1079] T ba7acad5a9564ea799667d7385684563 P af438b57668145879591e0bb4e892851: Deleting log segment in path: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515592857258-3463-0/minicluster-data/ts-0-root/wals/ba7acad5a9564ea799667d7385684563/wal-000000015 (ops 72-76)
I20260812 06:19:56.241786  3578 log.cc:1079] T ba7acad5a9564ea799667d7385684563 P af438b57668145879591e0bb4e892851: Deleting log segment in path: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515592857258-3463-0/minicluster-data/ts-0-root/wals/ba7acad5a9564ea799667d7385684563/wal-000000016 (ops 77-81)
I20260812 06:19:56.241828  3578 log.cc:1079] T ba7acad5a9564ea799667d7385684563 P af438b57668145879591e0bb4e892851: Deleting log segment in path: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515592857258-3463-0/minicluster-data/ts-0-root/wals/ba7acad5a9564ea799667d7385684563/wal-000000017 (ops 82-86)
I20260812 06:19:56.241868  3578 log.cc:1079] T ba7acad5a9564ea799667d7385684563 P af438b57668145879591e0bb4e892851: Deleting log segment in path: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515592857258-3463-0/minicluster-data/ts-0-root/wals/ba7acad5a9564ea799667d7385684563/wal-000000018 (ops 87-90)
I20260812 06:19:56.241909  3578 log.cc:1079] T ba7acad5a9564ea799667d7385684563 P af438b57668145879591e0bb4e892851: Deleting log segment in path: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515592857258-3463-0/minicluster-data/ts-0-root/wals/ba7acad5a9564ea799667d7385684563/wal-000000019 (ops 91-95)
I20260812 06:19:56.241947  3578 log.cc:1079] T ba7acad5a9564ea799667d7385684563 P af438b57668145879591e0bb4e892851: Deleting log segment in path: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515592857258-3463-0/minicluster-data/ts-0-root/wals/ba7acad5a9564ea799667d7385684563/wal-000000020 (ops 96-100)
I20260812 06:19:56.241986  3578 log.cc:1079] T ba7acad5a9564ea799667d7385684563 P af438b57668145879591e0bb4e892851: Deleting log segment in path: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515592857258-3463-0/minicluster-data/ts-0-root/wals/ba7acad5a9564ea799667d7385684563/wal-000000021 (ops 101-105)
I20260812 06:19:56.242025  3578 log.cc:1079] T ba7acad5a9564ea799667d7385684563 P af438b57668145879591e0bb4e892851: Deleting log segment in path: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515592857258-3463-0/minicluster-data/ts-0-root/wals/ba7acad5a9564ea799667d7385684563/wal-000000022 (ops 106-110)
I20260812 06:19:56.242065  3578 log.cc:1079] T ba7acad5a9564ea799667d7385684563 P af438b57668145879591e0bb4e892851: Deleting log segment in path: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515592857258-3463-0/minicluster-data/ts-0-root/wals/ba7acad5a9564ea799667d7385684563/wal-000000023 (ops 111-115)
I20260812 06:19:56.242105  3578 log.cc:1079] T ba7acad5a9564ea799667d7385684563 P af438b57668145879591e0bb4e892851: Deleting log segment in path: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515592857258-3463-0/minicluster-data/ts-0-root/wals/ba7acad5a9564ea799667d7385684563/wal-000000024 (ops 116-120)
I20260812 06:19:56.242144  3578 log.cc:1079] T ba7acad5a9564ea799667d7385684563 P af438b57668145879591e0bb4e892851: Deleting log segment in path: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515592857258-3463-0/minicluster-data/ts-0-root/wals/ba7acad5a9564ea799667d7385684563/wal-000000025 (ops 121-125)
I20260812 06:19:56.268399  3578 maintenance_manager.cc:643] P af438b57668145879591e0bb4e892851: LogGCOp(ba7acad5a9564ea799667d7385684563) complete. Timing: real 0.027s	user 0.000s	sys 0.024s Metrics: {}
I20260812 06:19:56.268970  3647 maintenance_manager.cc:419] P af438b57668145879591e0bb4e892851: Scheduling UndoDeltaBlockGCOp(ba7acad5a9564ea799667d7385684563): 472 bytes on disk
I20260812 06:19:56.269661  3578 maintenance_manager.cc:643] P af438b57668145879591e0bb4e892851: UndoDeltaBlockGCOp(ba7acad5a9564ea799667d7385684563) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":68,"lbm_reads_lt_1ms":4}
I20260812 06:19:56.270233  3647 maintenance_manager.cc:419] P af438b57668145879591e0bb4e892851: Scheduling FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563): perf score=3.181125
I20260812 06:19:56.282631  3578 maintenance_manager.cc:643] P af438b57668145879591e0bb4e892851: FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563) complete. Timing: real 0.012s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4512901,"delete_count":0,"lbm_write_time_us":4961,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:56.283025  3647 maintenance_manager.cc:419] P af438b57668145879591e0bb4e892851: Scheduling FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563): perf score=2.188937
I20260812 06:19:56.292958  3578 maintenance_manager.cc:643] P af438b57668145879591e0bb4e892851: FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563) complete. Timing: real 0.010s	user 0.005s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3887,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:56.293533  3647 maintenance_manager.cc:419] P af438b57668145879591e0bb4e892851: Scheduling MajorDeltaCompactionOp(ba7acad5a9564ea799667d7385684563): perf score=1.000000
I20260812 06:19:56.458739  3578 maintenance_manager.cc:643] P af438b57668145879591e0bb4e892851: MajorDeltaCompactionOp(ba7acad5a9564ea799667d7385684563) complete. Timing: real 0.165s	user 0.123s	sys 0.039s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877327,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":552,"lbm_read_time_us":13136,"lbm_reads_lt_1ms":674,"lbm_write_time_us":32002,"lbm_writes_lt_1ms":643,"mutex_wait_us":49,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":6016,"thread_start_us":84,"threads_started":1,"update_count":3000}
I20260812 06:19:56.459415  3647 maintenance_manager.cc:419] P af438b57668145879591e0bb4e892851: Scheduling FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563): perf score=14.095187
I20260812 06:19:56.509992  3578 maintenance_manager.cc:643] P af438b57668145879591e0bb4e892851: FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563) complete. Timing: real 0.050s	user 0.031s	sys 0.012s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":19087,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:56.510547  3647 maintenance_manager.cc:419] P af438b57668145879591e0bb4e892851: Scheduling FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563): perf score=2.188937
I20260812 06:19:56.526100  3578 maintenance_manager.cc:643] P af438b57668145879591e0bb4e892851: FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563) complete. Timing: real 0.015s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5812,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:56.526700  3647 maintenance_manager.cc:419] P af438b57668145879591e0bb4e892851: Scheduling MajorDeltaCompactionOp(ba7acad5a9564ea799667d7385684563): perf score=1.000000
I20260812 06:19:56.682664  3578 maintenance_manager.cc:643] P af438b57668145879591e0bb4e892851: MajorDeltaCompactionOp(ba7acad5a9564ea799667d7385684563) complete. Timing: real 0.156s	user 0.104s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774686,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":200,"lbm_read_time_us":9583,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28362,"lbm_writes_lt_1ms":543,"mutex_wait_us":47,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":17152,"update_count":2500}
I20260812 06:19:56.683488  3647 maintenance_manager.cc:419] P af438b57668145879591e0bb4e892851: Scheduling FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563): perf score=14.095187
I20260812 06:19:56.731452  3578 maintenance_manager.cc:643] P af438b57668145879591e0bb4e892851: FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563) complete. Timing: real 0.048s	user 0.018s	sys 0.024s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19934,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:56.731928  3647 maintenance_manager.cc:419] P af438b57668145879591e0bb4e892851: Scheduling MajorDeltaCompactionOp(ba7acad5a9564ea799667d7385684563): perf score=1.000000
I20260812 06:19:56.892590  3578 maintenance_manager.cc:643] P af438b57668145879591e0bb4e892851: MajorDeltaCompactionOp(ba7acad5a9564ea799667d7385684563) complete. Timing: real 0.160s	user 0.124s	sys 0.032s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672158,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":211,"lbm_read_time_us":10988,"lbm_reads_lt_1ms":463,"lbm_write_time_us":24332,"lbm_writes_lt_1ms":443,"mutex_wait_us":51,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8064,"update_count":2000}
I20260812 06:19:56.893271  3647 maintenance_manager.cc:419] P af438b57668145879591e0bb4e892851: Scheduling FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563): perf score=14.095187
I20260812 06:19:56.945376  3578 maintenance_manager.cc:643] P af438b57668145879591e0bb4e892851: FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563) complete. Timing: real 0.052s	user 0.037s	sys 0.008s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20119,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:56.945906  3647 maintenance_manager.cc:419] P af438b57668145879591e0bb4e892851: Scheduling FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563): perf score=2.188937
I20260812 06:19:56.958040  3578 maintenance_manager.cc:643] P af438b57668145879591e0bb4e892851: FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563) complete. Timing: real 0.012s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4229,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:56.958603  3647 maintenance_manager.cc:419] P af438b57668145879591e0bb4e892851: Scheduling MajorDeltaCompactionOp(ba7acad5a9564ea799667d7385684563): perf score=1.000000
I20260812 06:19:57.138404  3578 maintenance_manager.cc:643] P af438b57668145879591e0bb4e892851: MajorDeltaCompactionOp(ba7acad5a9564ea799667d7385684563) complete. Timing: real 0.180s	user 0.139s	sys 0.036s 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":220,"lbm_read_time_us":11073,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29392,"lbm_writes_lt_1ms":543,"mutex_wait_us":24,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8576,"update_count":2500}
I20260812 06:19:57.139088  3647 maintenance_manager.cc:419] P af438b57668145879591e0bb4e892851: Scheduling FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563): perf score=14.095187
I20260812 06:19:57.190784  3578 maintenance_manager.cc:643] P af438b57668145879591e0bb4e892851: FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563) complete. Timing: real 0.052s	user 0.042s	sys 0.008s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22654,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:57.191232  3647 maintenance_manager.cc:419] P af438b57668145879591e0bb4e892851: Scheduling FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563): perf score=2.188937
I20260812 06:19:57.201706  3578 maintenance_manager.cc:643] P af438b57668145879591e0bb4e892851: FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563) complete. Timing: real 0.010s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4032,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:57.202250  3647 maintenance_manager.cc:419] P af438b57668145879591e0bb4e892851: Scheduling MajorDeltaCompactionOp(ba7acad5a9564ea799667d7385684563): perf score=1.000000
I20260812 06:19:57.353749  3578 maintenance_manager.cc:643] P af438b57668145879591e0bb4e892851: MajorDeltaCompactionOp(ba7acad5a9564ea799667d7385684563) complete. Timing: real 0.151s	user 0.114s	sys 0.035s 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":809,"lbm_read_time_us":10999,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29213,"lbm_writes_lt_1ms":543,"mutex_wait_us":223,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9600,"update_count":2500}
I20260812 06:19:57.354387  3647 maintenance_manager.cc:419] P af438b57668145879591e0bb4e892851: Scheduling FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563): perf score=10.126437
I20260812 06:19:57.388432  3578 maintenance_manager.cc:643] P af438b57668145879591e0bb4e892851: FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563) complete. Timing: real 0.034s	user 0.014s	sys 0.016s Metrics: {"bytes_written":12307495,"delete_count":0,"lbm_write_time_us":14550,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:57.389021  3647 maintenance_manager.cc:419] P af438b57668145879591e0bb4e892851: Scheduling FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563): perf score=2.188937
I20260812 06:19:57.403861  3578 maintenance_manager.cc:643] P af438b57668145879591e0bb4e892851: FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563) complete. Timing: real 0.015s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5469,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:57.404717  3647 maintenance_manager.cc:419] P af438b57668145879591e0bb4e892851: Scheduling MajorDeltaCompactionOp(ba7acad5a9564ea799667d7385684563): perf score=1.000000
I20260812 06:19:57.533386  3578 maintenance_manager.cc:643] P af438b57668145879591e0bb4e892851: MajorDeltaCompactionOp(ba7acad5a9564ea799667d7385684563) complete. Timing: real 0.128s	user 0.104s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672282,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":986,"lbm_read_time_us":7513,"lbm_reads_lt_1ms":464,"lbm_write_time_us":26152,"lbm_writes_lt_1ms":443,"mutex_wait_us":336,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2000}
I20260812 06:19:57.533988  3647 maintenance_manager.cc:419] P af438b57668145879591e0bb4e892851: Scheduling FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563): perf score=10.126437
I20260812 06:19:57.573607  3578 maintenance_manager.cc:643] P af438b57668145879591e0bb4e892851: FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563) complete. Timing: real 0.039s	user 0.027s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17746,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:57.574132  3647 maintenance_manager.cc:419] P af438b57668145879591e0bb4e892851: Scheduling FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563): perf score=2.188937
I20260812 06:19:57.585536  3578 maintenance_manager.cc:643] P af438b57668145879591e0bb4e892851: FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563) complete. Timing: real 0.011s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4307,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:57.586182  3647 maintenance_manager.cc:419] P af438b57668145879591e0bb4e892851: Scheduling FlushMRSOp(ba7acad5a9564ea799667d7385684563): perf score=1.000000
I20260812 06:19:57.618007  3578 maintenance_manager.cc:643] P af438b57668145879591e0bb4e892851: FlushMRSOp(ba7acad5a9564ea799667d7385684563) complete. Timing: real 0.032s	user 0.030s	sys 0.001s Metrics: {"bytes_written":1193505,"cfile_init":1,"dirs.queue_time_us":60,"dirs.run_cpu_time_us":193,"dirs.run_wall_time_us":1579,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1701,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:57.618728  3647 maintenance_manager.cc:419] P af438b57668145879591e0bb4e892851: Scheduling LogGCOp(ba7acad5a9564ea799667d7385684563): free 124257494 bytes of WAL
I20260812 06:19:57.618978  3578 log_reader.cc:385] T ba7acad5a9564ea799667d7385684563: removed 12 log segments from log reader
I20260812 06:19:57.619048  3578 log.cc:1079] T ba7acad5a9564ea799667d7385684563 P af438b57668145879591e0bb4e892851: Deleting log segment in path: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515592857258-3463-0/minicluster-data/ts-0-root/wals/ba7acad5a9564ea799667d7385684563/wal-000000026 (ops 126-130)
I20260812 06:19:57.619107  3578 log.cc:1079] T ba7acad5a9564ea799667d7385684563 P af438b57668145879591e0bb4e892851: Deleting log segment in path: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515592857258-3463-0/minicluster-data/ts-0-root/wals/ba7acad5a9564ea799667d7385684563/wal-000000027 (ops 131-135)
I20260812 06:19:57.619164  3578 log.cc:1079] T ba7acad5a9564ea799667d7385684563 P af438b57668145879591e0bb4e892851: Deleting log segment in path: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515592857258-3463-0/minicluster-data/ts-0-root/wals/ba7acad5a9564ea799667d7385684563/wal-000000028 (ops 136-140)
I20260812 06:19:57.619206  3578 log.cc:1079] T ba7acad5a9564ea799667d7385684563 P af438b57668145879591e0bb4e892851: Deleting log segment in path: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515592857258-3463-0/minicluster-data/ts-0-root/wals/ba7acad5a9564ea799667d7385684563/wal-000000029 (ops 141-145)
I20260812 06:19:57.619242  3578 log.cc:1079] T ba7acad5a9564ea799667d7385684563 P af438b57668145879591e0bb4e892851: Deleting log segment in path: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515592857258-3463-0/minicluster-data/ts-0-root/wals/ba7acad5a9564ea799667d7385684563/wal-000000030 (ops 146-150)
I20260812 06:19:57.619294  3578 log.cc:1079] T ba7acad5a9564ea799667d7385684563 P af438b57668145879591e0bb4e892851: Deleting log segment in path: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515592857258-3463-0/minicluster-data/ts-0-root/wals/ba7acad5a9564ea799667d7385684563/wal-000000031 (ops 151-155)
I20260812 06:19:57.619330  3578 log.cc:1079] T ba7acad5a9564ea799667d7385684563 P af438b57668145879591e0bb4e892851: Deleting log segment in path: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515592857258-3463-0/minicluster-data/ts-0-root/wals/ba7acad5a9564ea799667d7385684563/wal-000000032 (ops 156-160)
I20260812 06:19:57.619367  3578 log.cc:1079] T ba7acad5a9564ea799667d7385684563 P af438b57668145879591e0bb4e892851: Deleting log segment in path: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515592857258-3463-0/minicluster-data/ts-0-root/wals/ba7acad5a9564ea799667d7385684563/wal-000000033 (ops 161-165)
I20260812 06:19:57.619405  3578 log.cc:1079] T ba7acad5a9564ea799667d7385684563 P af438b57668145879591e0bb4e892851: Deleting log segment in path: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515592857258-3463-0/minicluster-data/ts-0-root/wals/ba7acad5a9564ea799667d7385684563/wal-000000034 (ops 166-170)
I20260812 06:19:57.619441  3578 log.cc:1079] T ba7acad5a9564ea799667d7385684563 P af438b57668145879591e0bb4e892851: Deleting log segment in path: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515592857258-3463-0/minicluster-data/ts-0-root/wals/ba7acad5a9564ea799667d7385684563/wal-000000035 (ops 171-175)
I20260812 06:19:57.619477  3578 log.cc:1079] T ba7acad5a9564ea799667d7385684563 P af438b57668145879591e0bb4e892851: Deleting log segment in path: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515592857258-3463-0/minicluster-data/ts-0-root/wals/ba7acad5a9564ea799667d7385684563/wal-000000036 (ops 176-180)
I20260812 06:19:57.619514  3578 log.cc:1079] T ba7acad5a9564ea799667d7385684563 P af438b57668145879591e0bb4e892851: Deleting log segment in path: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515592857258-3463-0/minicluster-data/ts-0-root/wals/ba7acad5a9564ea799667d7385684563/wal-000000037 (ops 181-184)
I20260812 06:19:57.646350  3578 maintenance_manager.cc:643] P af438b57668145879591e0bb4e892851: LogGCOp(ba7acad5a9564ea799667d7385684563) complete. Timing: real 0.027s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:19:57.646775  3647 maintenance_manager.cc:419] P af438b57668145879591e0bb4e892851: Scheduling FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563): perf score=3.181125
I20260812 06:19:57.659354  3578 maintenance_manager.cc:643] P af438b57668145879591e0bb4e892851: FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563) complete. Timing: real 0.012s	user 0.005s	sys 0.005s Metrics: {"bytes_written":5005191,"delete_count":0,"lbm_write_time_us":5079,"lbm_writes_lt_1ms":125,"reinsert_count":0,"update_count":610}
I20260812 06:19:57.659756  3647 maintenance_manager.cc:419] P af438b57668145879591e0bb4e892851: Scheduling FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563): perf score=2.188937
I20260812 06:19:57.671208  3578 maintenance_manager.cc:643] P af438b57668145879591e0bb4e892851: FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563) complete. Timing: real 0.011s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3200105,"delete_count":0,"lbm_write_time_us":3646,"lbm_writes_lt_1ms":81,"reinsert_count":0,"update_count":390}
I20260812 06:19:57.671814  3647 maintenance_manager.cc:419] P af438b57668145879591e0bb4e892851: Scheduling UndoDeltaBlockGCOp(ba7acad5a9564ea799667d7385684563): 463 bytes on disk
I20260812 06:19:57.672389  3578 maintenance_manager.cc:643] P af438b57668145879591e0bb4e892851: UndoDeltaBlockGCOp(ba7acad5a9564ea799667d7385684563) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":84,"lbm_reads_lt_1ms":4}
I20260812 06:19:57.673206  3647 maintenance_manager.cc:419] P af438b57668145879591e0bb4e892851: Scheduling MajorDeltaCompactionOp(ba7acad5a9564ea799667d7385684563): perf score=1.000000
I20260812 06:19:57.845463  3578 maintenance_manager.cc:643] P af438b57668145879591e0bb4e892851: MajorDeltaCompactionOp(ba7acad5a9564ea799667d7385684563) complete. Timing: real 0.172s	user 0.134s	sys 0.037s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877316,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":745,"lbm_read_time_us":12300,"lbm_reads_lt_1ms":674,"lbm_write_time_us":34161,"lbm_writes_lt_1ms":643,"mutex_wait_us":285,"peak_mem_usage":75542472,"reinsert_count":0,"thread_start_us":94,"threads_started":1,"update_count":3000}
I20260812 06:19:57.846295  3647 maintenance_manager.cc:419] P af438b57668145879591e0bb4e892851: Scheduling FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563): perf score=14.095187
I20260812 06:19:57.891883  3578 maintenance_manager.cc:643] P af438b57668145879591e0bb4e892851: FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563) complete. Timing: real 0.045s	user 0.028s	sys 0.012s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19417,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:57.892557  3647 maintenance_manager.cc:419] P af438b57668145879591e0bb4e892851: Scheduling FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563): perf score=2.188937
I20260812 06:19:57.905874  3578 maintenance_manager.cc:643] P af438b57668145879591e0bb4e892851: FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563) complete. Timing: real 0.013s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4461,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:57.906451  3647 maintenance_manager.cc:419] P af438b57668145879591e0bb4e892851: Scheduling MajorDeltaCompactionOp(ba7acad5a9564ea799667d7385684563): perf score=1.000000
I20260812 06:19:57.972498  3463 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.829s	user 1.823s	sys 0.104s
I20260812 06:19:58.034379  3463 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.061s	user 0.004s	sys 0.000s
I20260812 06:19:58.035096  3463 tablet_server.cc:179] TabletServer@127.3.97.193:0 shutting down...
I20260812 06:19:58.046434  3578 maintenance_manager.cc:643] P af438b57668145879591e0bb4e892851: MajorDeltaCompactionOp(ba7acad5a9564ea799667d7385684563) complete. Timing: real 0.140s	user 0.112s	sys 0.026s 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":346,"lbm_read_time_us":9485,"lbm_reads_lt_1ms":564,"lbm_write_time_us":27765,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":17280,"update_count":2500}
I20260812 06:19:58.047264  3647 maintenance_manager.cc:419] P af438b57668145879591e0bb4e892851: Scheduling FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563): perf score=6.157687
I20260812 06:19:58.070415  3578 maintenance_manager.cc:643] P af438b57668145879591e0bb4e892851: FlushDeltaMemStoresOp(ba7acad5a9564ea799667d7385684563) complete. Timing: real 0.023s	user 0.014s	sys 0.008s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":9885,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:19:58.071039  3463 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:58.071478  3463 tablet_replica.cc:333] T ba7acad5a9564ea799667d7385684563 P af438b57668145879591e0bb4e892851: stopping tablet replica
I20260812 06:19:58.071727  3463 raft_consensus.cc:2243] T ba7acad5a9564ea799667d7385684563 P af438b57668145879591e0bb4e892851 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:58.071986  3463 raft_consensus.cc:2272] T ba7acad5a9564ea799667d7385684563 P af438b57668145879591e0bb4e892851 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:58.087194  3463 tablet_server.cc:196] TabletServer@127.3.97.193:0 shutdown complete.
I20260812 06:19:58.093559  3463 master.cc:562] Master@127.3.97.254:39441 shutting down...
I20260812 06:19:58.097592  3463 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 2b7cf0ec21a74ad1a9afd341831664c5 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:58.097779  3463 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 2b7cf0ec21a74ad1a9afd341831664c5 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:58.097868  3463 tablet_replica.cc:333] T 00000000000000000000000000000000 P 2b7cf0ec21a74ad1a9afd341831664c5: stopping tablet replica
I20260812 06:19:58.110334  3463 master.cc:584] Master@127.3.97.254:39441 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5332 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:19:58.200271  3463 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.3.97.254:43953
I20260812 06:19:58.200686  3463 file_cache.cc:504] Constructed file cache file cache with capacity 419430
I20260812 06:19:58.203032  3463 server_base.cc:1061] running on GCE node
W20260812 06:19:58.203075  3682 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:58.203094  3683 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:58.202994  3687 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:58.203439  3463 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:58.203502  3463 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:58.203528  3463 hybrid_clock.cc:648] HybridClock initialized: now 1786515598203527 us; error 0 us; skew 500 ppm
I20260812 06:19:58.204360  3463 webserver.cc:533] Webserver started at http://127.3.97.254:36725/ using document root <none> and password file <none>
I20260812 06:19:58.204541  3463 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:58.204608  3463 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:58.204689  3463 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:58.205088  3463 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515592857258-3463-0/minicluster-data/master-0-root/instance:
uuid: "98c968c46e424a0ead9474d313ebc108"
format_stamp: "Formatted at 2026-08-12 06:19:58 on dist-test-slave-9gcw"
I20260812 06:19:58.206693  3463 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:19:58.207608  3692 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:58.207886  3463 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:19:58.207978  3463 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515592857258-3463-0/minicluster-data/master-0-root
uuid: "98c968c46e424a0ead9474d313ebc108"
format_stamp: "Formatted at 2026-08-12 06:19:58 on dist-test-slave-9gcw"
I20260812 06:19:58.208069  3463 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515592857258-3463-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515592857258-3463-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515592857258-3463-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:58.218391  3463 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:58.218770  3463 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:58.223016  3463 rpc_server.cc:307] RPC server started. Bound to: 127.3.97.254:43953
I20260812 06:19:58.225425  3760 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.3.97.254:43953 every 8 connection(s)
I20260812 06:19:58.225725  3761 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:58.233080  3761 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 98c968c46e424a0ead9474d313ebc108: Bootstrap starting.
I20260812 06:19:58.233935  3761 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 98c968c46e424a0ead9474d313ebc108: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:58.234954  3761 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 98c968c46e424a0ead9474d313ebc108: No bootstrap required, opened a new log
I20260812 06:19:58.235368  3761 raft_consensus.cc:359] T 00000000000000000000000000000000 P 98c968c46e424a0ead9474d313ebc108 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "98c968c46e424a0ead9474d313ebc108" member_type: VOTER }
I20260812 06:19:58.235452  3761 raft_consensus.cc:385] T 00000000000000000000000000000000 P 98c968c46e424a0ead9474d313ebc108 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:58.235507  3761 raft_consensus.cc:740] T 00000000000000000000000000000000 P 98c968c46e424a0ead9474d313ebc108 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 98c968c46e424a0ead9474d313ebc108, State: Initialized, Role: FOLLOWER
I20260812 06:19:58.235682  3761 consensus_queue.cc:260] T 00000000000000000000000000000000 P 98c968c46e424a0ead9474d313ebc108 [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: "98c968c46e424a0ead9474d313ebc108" member_type: VOTER }
I20260812 06:19:58.235775  3761 raft_consensus.cc:399] T 00000000000000000000000000000000 P 98c968c46e424a0ead9474d313ebc108 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:58.235833  3761 raft_consensus.cc:493] T 00000000000000000000000000000000 P 98c968c46e424a0ead9474d313ebc108 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:58.235893  3761 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 98c968c46e424a0ead9474d313ebc108 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:58.236567  3761 raft_consensus.cc:515] T 00000000000000000000000000000000 P 98c968c46e424a0ead9474d313ebc108 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "98c968c46e424a0ead9474d313ebc108" member_type: VOTER }
I20260812 06:19:58.236712  3761 leader_election.cc:304] T 00000000000000000000000000000000 P 98c968c46e424a0ead9474d313ebc108 [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: 98c968c46e424a0ead9474d313ebc108; no voters: 
I20260812 06:19:58.236913  3761 leader_election.cc:290] T 00000000000000000000000000000000 P 98c968c46e424a0ead9474d313ebc108 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:58.237067  3764 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 98c968c46e424a0ead9474d313ebc108 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:58.237286  3764 raft_consensus.cc:697] T 00000000000000000000000000000000 P 98c968c46e424a0ead9474d313ebc108 [term 1 LEADER]: Becoming Leader. State: Replica: 98c968c46e424a0ead9474d313ebc108, State: Running, Role: LEADER
I20260812 06:19:58.237416  3761 sys_catalog.cc:565] T 00000000000000000000000000000000 P 98c968c46e424a0ead9474d313ebc108 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:58.237458  3764 consensus_queue.cc:237] T 00000000000000000000000000000000 P 98c968c46e424a0ead9474d313ebc108 [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: "98c968c46e424a0ead9474d313ebc108" member_type: VOTER }
I20260812 06:19:58.237946  3765 sys_catalog.cc:455] T 00000000000000000000000000000000 P 98c968c46e424a0ead9474d313ebc108 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "98c968c46e424a0ead9474d313ebc108" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "98c968c46e424a0ead9474d313ebc108" member_type: VOTER } }
I20260812 06:19:58.238058  3765 sys_catalog.cc:458] T 00000000000000000000000000000000 P 98c968c46e424a0ead9474d313ebc108 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:58.237963  3769 sys_catalog.cc:455] T 00000000000000000000000000000000 P 98c968c46e424a0ead9474d313ebc108 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 98c968c46e424a0ead9474d313ebc108. Latest consensus state: current_term: 1 leader_uuid: "98c968c46e424a0ead9474d313ebc108" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "98c968c46e424a0ead9474d313ebc108" member_type: VOTER } }
I20260812 06:19:58.238150  3769 sys_catalog.cc:458] T 00000000000000000000000000000000 P 98c968c46e424a0ead9474d313ebc108 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:58.238633  3776 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:58.239327  3776 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:58.239493  3463 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:58.241398  3776 catalog_manager.cc:1383] Generated new cluster ID: 0faaf993471c4b13b0dc71c75adef6aa
I20260812 06:19:58.241460  3776 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:58.248973  3776 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:58.249526  3776 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:58.255534  3776 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 98c968c46e424a0ead9474d313ebc108: Generated new TSK 0
I20260812 06:19:58.255735  3776 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:58.272214  3463 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:58.274446  3788 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:58.274502  3789 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:58.274586  3463 server_base.cc:1061] running on GCE node
W20260812 06:19:58.274693  3791 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:58.274888  3463 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:58.274931  3463 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:58.274947  3463 hybrid_clock.cc:648] HybridClock initialized: now 1786515598274948 us; error 0 us; skew 500 ppm
I20260812 06:19:58.275802  3463 webserver.cc:533] Webserver started at http://127.3.97.193:39397/ using document root <none> and password file <none>
I20260812 06:19:58.275949  3463 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:58.275992  3463 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:58.276046  3463 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:58.276401  3463 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515592857258-3463-0/minicluster-data/ts-0-root/instance:
uuid: "b86b9914ad884bcfbe54d4aa78338031"
format_stamp: "Formatted at 2026-08-12 06:19:58 on dist-test-slave-9gcw"
I20260812 06:19:58.277940  3463 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:58.278833  3797 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:58.279088  3463 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:58.279174  3463 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515592857258-3463-0/minicluster-data/ts-0-root
uuid: "b86b9914ad884bcfbe54d4aa78338031"
format_stamp: "Formatted at 2026-08-12 06:19:58 on dist-test-slave-9gcw"
I20260812 06:19:58.279264  3463 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515592857258-3463-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515592857258-3463-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515592857258-3463-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:58.296979  3463 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:58.297408  3463 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:58.297742  3463 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:58.298210  3463 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:58.298272  3463 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:58.298336  3463 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:58.298391  3463 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:58.302865  3463 rpc_server.cc:307] RPC server started. Bound to: 127.3.97.193:39679
I20260812 06:19:58.302901  3870 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.3.97.193:39679 every 8 connection(s)
I20260812 06:19:58.311801  3872 heartbeater.cc:344] Connected to a master server at 127.3.97.254:43953
I20260812 06:19:58.311939  3872 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:58.312191  3872 heartbeater.cc:507] Master 127.3.97.254:43953 requested a full tablet report, sending...
I20260812 06:19:58.312877  3714 ts_manager.cc:194] Registered new tserver with Master: b86b9914ad884bcfbe54d4aa78338031 (127.3.97.193:39679)
I20260812 06:19:58.313427  3463 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.010101375s
I20260812 06:19:58.313766  3714 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:36488
I20260812 06:19:58.320407  3714 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:36492:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:19:58.329128  3829 tablet_service.cc:1511] Processing CreateTablet for tablet 5bb2dbb4a7f6472f80f5882afcb194cc (DEFAULT_TABLE table=heavy-update-compaction-test [id=62d8da5c526a4a44b735517e64c48009]), partition=
I20260812 06:19:58.329479  3829 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 5bb2dbb4a7f6472f80f5882afcb194cc. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:58.331421  3886 tablet_bootstrap.cc:492] T 5bb2dbb4a7f6472f80f5882afcb194cc P b86b9914ad884bcfbe54d4aa78338031: Bootstrap starting.
I20260812 06:19:58.332242  3886 tablet_bootstrap.cc:654] T 5bb2dbb4a7f6472f80f5882afcb194cc P b86b9914ad884bcfbe54d4aa78338031: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:58.333389  3886 tablet_bootstrap.cc:492] T 5bb2dbb4a7f6472f80f5882afcb194cc P b86b9914ad884bcfbe54d4aa78338031: No bootstrap required, opened a new log
I20260812 06:19:58.333487  3886 ts_tablet_manager.cc:1403] T 5bb2dbb4a7f6472f80f5882afcb194cc P b86b9914ad884bcfbe54d4aa78338031: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:58.333927  3886 raft_consensus.cc:359] T 5bb2dbb4a7f6472f80f5882afcb194cc P b86b9914ad884bcfbe54d4aa78338031 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b86b9914ad884bcfbe54d4aa78338031" member_type: VOTER last_known_addr { host: "127.3.97.193" port: 39679 } }
I20260812 06:19:58.334017  3886 raft_consensus.cc:385] T 5bb2dbb4a7f6472f80f5882afcb194cc P b86b9914ad884bcfbe54d4aa78338031 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:58.334079  3886 raft_consensus.cc:740] T 5bb2dbb4a7f6472f80f5882afcb194cc P b86b9914ad884bcfbe54d4aa78338031 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: b86b9914ad884bcfbe54d4aa78338031, State: Initialized, Role: FOLLOWER
I20260812 06:19:58.334270  3886 consensus_queue.cc:260] T 5bb2dbb4a7f6472f80f5882afcb194cc P b86b9914ad884bcfbe54d4aa78338031 [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: "b86b9914ad884bcfbe54d4aa78338031" member_type: VOTER last_known_addr { host: "127.3.97.193" port: 39679 } }
I20260812 06:19:58.334388  3886 raft_consensus.cc:399] T 5bb2dbb4a7f6472f80f5882afcb194cc P b86b9914ad884bcfbe54d4aa78338031 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:58.334431  3886 raft_consensus.cc:493] T 5bb2dbb4a7f6472f80f5882afcb194cc P b86b9914ad884bcfbe54d4aa78338031 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:58.334496  3886 raft_consensus.cc:3060] T 5bb2dbb4a7f6472f80f5882afcb194cc P b86b9914ad884bcfbe54d4aa78338031 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:58.335327  3886 raft_consensus.cc:515] T 5bb2dbb4a7f6472f80f5882afcb194cc P b86b9914ad884bcfbe54d4aa78338031 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b86b9914ad884bcfbe54d4aa78338031" member_type: VOTER last_known_addr { host: "127.3.97.193" port: 39679 } }
I20260812 06:19:58.335487  3886 leader_election.cc:304] T 5bb2dbb4a7f6472f80f5882afcb194cc P b86b9914ad884bcfbe54d4aa78338031 [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: b86b9914ad884bcfbe54d4aa78338031; no voters: 
I20260812 06:19:58.335706  3886 leader_election.cc:290] T 5bb2dbb4a7f6472f80f5882afcb194cc P b86b9914ad884bcfbe54d4aa78338031 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:58.335856  3888 raft_consensus.cc:2804] T 5bb2dbb4a7f6472f80f5882afcb194cc P b86b9914ad884bcfbe54d4aa78338031 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:58.336023  3886 ts_tablet_manager.cc:1434] T 5bb2dbb4a7f6472f80f5882afcb194cc P b86b9914ad884bcfbe54d4aa78338031: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:19:58.336078  3888 raft_consensus.cc:697] T 5bb2dbb4a7f6472f80f5882afcb194cc P b86b9914ad884bcfbe54d4aa78338031 [term 1 LEADER]: Becoming Leader. State: Replica: b86b9914ad884bcfbe54d4aa78338031, State: Running, Role: LEADER
I20260812 06:19:58.336031  3872 heartbeater.cc:499] Master 127.3.97.254:43953 was elected leader, sending a full tablet report...
I20260812 06:19:58.336256  3888 consensus_queue.cc:237] T 5bb2dbb4a7f6472f80f5882afcb194cc P b86b9914ad884bcfbe54d4aa78338031 [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: "b86b9914ad884bcfbe54d4aa78338031" member_type: VOTER last_known_addr { host: "127.3.97.193" port: 39679 } }
I20260812 06:19:58.337670  3714 catalog_manager.cc:5719] T 5bb2dbb4a7f6472f80f5882afcb194cc P b86b9914ad884bcfbe54d4aa78338031 reported cstate change: term changed from 0 to 1, leader changed from <none> to b86b9914ad884bcfbe54d4aa78338031 (127.3.97.193). New cstate: current_term: 1 leader_uuid: "b86b9914ad884bcfbe54d4aa78338031" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b86b9914ad884bcfbe54d4aa78338031" member_type: VOTER last_known_addr { host: "127.3.97.193" port: 39679 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:58.395429  3463 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.051s	user 0.007s	sys 0.014s
I20260812 06:19:58.553814  3873 maintenance_manager.cc:419] P b86b9914ad884bcfbe54d4aa78338031: Scheduling FlushMRSOp(5bb2dbb4a7f6472f80f5882afcb194cc): perf score=19.054940
I20260812 06:19:58.736415  3802 maintenance_manager.cc:643] P b86b9914ad884bcfbe54d4aa78338031: FlushMRSOp(5bb2dbb4a7f6472f80f5882afcb194cc) complete. Timing: real 0.182s	user 0.113s	sys 0.061s Metrics: {"bytes_written":15999660,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":255,"dirs.run_cpu_time_us":193,"dirs.run_wall_time_us":930,"drs_written":1,"lbm_read_time_us":77,"lbm_reads_lt_1ms":4,"lbm_write_time_us":48584,"lbm_writes_lt_1ms":857,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"spinlock_wait_cycles":7552,"update_count":1950}
I20260812 06:19:58.737269  3873 maintenance_manager.cc:419] P b86b9914ad884bcfbe54d4aa78338031: Scheduling LogGCOp(5bb2dbb4a7f6472f80f5882afcb194cc): free 20743880 bytes of WAL
I20260812 06:19:58.737526  3802 log_reader.cc:385] T 5bb2dbb4a7f6472f80f5882afcb194cc: removed 2 log segments from log reader
I20260812 06:19:58.737594  3802 log.cc:1079] T 5bb2dbb4a7f6472f80f5882afcb194cc P b86b9914ad884bcfbe54d4aa78338031: Deleting log segment in path: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515592857258-3463-0/minicluster-data/ts-0-root/wals/5bb2dbb4a7f6472f80f5882afcb194cc/wal-000000001 (ops 1-6)
I20260812 06:19:58.737673  3802 log.cc:1079] T 5bb2dbb4a7f6472f80f5882afcb194cc P b86b9914ad884bcfbe54d4aa78338031: Deleting log segment in path: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515592857258-3463-0/minicluster-data/ts-0-root/wals/5bb2dbb4a7f6472f80f5882afcb194cc/wal-000000002 (ops 7-11)
I20260812 06:19:58.744017  3802 maintenance_manager.cc:643] P b86b9914ad884bcfbe54d4aa78338031: LogGCOp(5bb2dbb4a7f6472f80f5882afcb194cc) complete. Timing: real 0.007s	user 0.000s	sys 0.004s Metrics: {}
I20260812 06:19:58.744513  3873 maintenance_manager.cc:419] P b86b9914ad884bcfbe54d4aa78338031: Scheduling FlushDeltaMemStoresOp(5bb2dbb4a7f6472f80f5882afcb194cc): perf score=2.188937
I20260812 06:19:58.769914  3802 maintenance_manager.cc:643] P b86b9914ad884bcfbe54d4aa78338031: FlushDeltaMemStoresOp(5bb2dbb4a7f6472f80f5882afcb194cc) complete. Timing: real 0.025s	user 0.014s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6221,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:58.770493  3873 maintenance_manager.cc:419] P b86b9914ad884bcfbe54d4aa78338031: Scheduling UndoDeltaBlockGCOp(5bb2dbb4a7f6472f80f5882afcb194cc): 16821650 bytes on disk
I20260812 06:19:58.770910  3802 maintenance_manager.cc:643] P b86b9914ad884bcfbe54d4aa78338031: UndoDeltaBlockGCOp(5bb2dbb4a7f6472f80f5882afcb194cc) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4}
I20260812 06:19:58.771337  3873 maintenance_manager.cc:419] P b86b9914ad884bcfbe54d4aa78338031: Scheduling FlushDeltaMemStoresOp(5bb2dbb4a7f6472f80f5882afcb194cc): perf score=2.188937
I20260812 06:19:58.784591  3802 maintenance_manager.cc:643] P b86b9914ad884bcfbe54d4aa78338031: FlushDeltaMemStoresOp(5bb2dbb4a7f6472f80f5882afcb194cc) complete. Timing: real 0.013s	user 0.003s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4822,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:58.785091  3873 maintenance_manager.cc:419] P b86b9914ad884bcfbe54d4aa78338031: Scheduling MajorDeltaCompactionOp(5bb2dbb4a7f6472f80f5882afcb194cc): perf score=1.000000
I20260812 06:19:58.964027  3802 maintenance_manager.cc:643] P b86b9914ad884bcfbe54d4aa78338031: MajorDeltaCompactionOp(5bb2dbb4a7f6472f80f5882afcb194cc) complete. Timing: real 0.179s	user 0.110s	sys 0.069s Metrics: {"cfile_cache_miss":623,"cfile_cache_miss_bytes":28507973,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":551,"lbm_read_time_us":13861,"lbm_reads_lt_1ms":659,"lbm_write_time_us":30697,"lbm_writes_lt_1ms":633,"mutex_wait_us":85,"peak_mem_usage":74091738,"reinsert_count":0,"spinlock_wait_cycles":9600,"thread_start_us":353,"threads_started":5,"update_count":2950}
I20260812 06:19:58.964767  3873 maintenance_manager.cc:419] P b86b9914ad884bcfbe54d4aa78338031: Scheduling FlushDeltaMemStoresOp(5bb2dbb4a7f6472f80f5882afcb194cc): perf score=14.095187
I20260812 06:19:59.014226  3802 maintenance_manager.cc:643] P b86b9914ad884bcfbe54d4aa78338031: FlushDeltaMemStoresOp(5bb2dbb4a7f6472f80f5882afcb194cc) complete. Timing: real 0.049s	user 0.033s	sys 0.015s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21435,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:59.014827  3873 maintenance_manager.cc:419] P b86b9914ad884bcfbe54d4aa78338031: Scheduling FlushDeltaMemStoresOp(5bb2dbb4a7f6472f80f5882afcb194cc): perf score=2.188937
I20260812 06:19:59.032737  3802 maintenance_manager.cc:643] P b86b9914ad884bcfbe54d4aa78338031: FlushDeltaMemStoresOp(5bb2dbb4a7f6472f80f5882afcb194cc) complete. Timing: real 0.018s	user 0.012s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6831,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:59.033337  3873 maintenance_manager.cc:419] P b86b9914ad884bcfbe54d4aa78338031: Scheduling MajorDeltaCompactionOp(5bb2dbb4a7f6472f80f5882afcb194cc): perf score=1.000000
I20260812 06:19:59.210003  3802 maintenance_manager.cc:643] P b86b9914ad884bcfbe54d4aa78338031: MajorDeltaCompactionOp(5bb2dbb4a7f6472f80f5882afcb194cc) complete. Timing: real 0.176s	user 0.144s	sys 0.027s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":621,"lbm_read_time_us":11483,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32395,"lbm_writes_lt_1ms":543,"mutex_wait_us":372,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":30464,"update_count":2500}
I20260812 06:19:59.211226  3873 maintenance_manager.cc:419] P b86b9914ad884bcfbe54d4aa78338031: Scheduling FlushDeltaMemStoresOp(5bb2dbb4a7f6472f80f5882afcb194cc): perf score=14.095187
I20260812 06:19:59.267584  3802 maintenance_manager.cc:643] P b86b9914ad884bcfbe54d4aa78338031: FlushDeltaMemStoresOp(5bb2dbb4a7f6472f80f5882afcb194cc) complete. Timing: real 0.056s	user 0.036s	sys 0.011s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":22277,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:59.268201  3873 maintenance_manager.cc:419] P b86b9914ad884bcfbe54d4aa78338031: Scheduling MajorDeltaCompactionOp(5bb2dbb4a7f6472f80f5882afcb194cc): perf score=1.000000
I20260812 06:19:59.426620  3802 maintenance_manager.cc:643] P b86b9914ad884bcfbe54d4aa78338031: MajorDeltaCompactionOp(5bb2dbb4a7f6472f80f5882afcb194cc) complete. Timing: real 0.158s	user 0.107s	sys 0.044s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713151,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":1129,"lbm_read_time_us":9774,"lbm_reads_lt_1ms":463,"lbm_write_time_us":27155,"lbm_writes_lt_1ms":443,"mutex_wait_us":335,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":16512,"update_count":2000}
I20260812 06:19:59.427155  3873 maintenance_manager.cc:419] P b86b9914ad884bcfbe54d4aa78338031: Scheduling FlushDeltaMemStoresOp(5bb2dbb4a7f6472f80f5882afcb194cc): perf score=14.095187
I20260812 06:19:59.477242  3802 maintenance_manager.cc:643] P b86b9914ad884bcfbe54d4aa78338031: FlushDeltaMemStoresOp(5bb2dbb4a7f6472f80f5882afcb194cc) complete. Timing: real 0.050s	user 0.035s	sys 0.015s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":22226,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:59.477697  3873 maintenance_manager.cc:419] P b86b9914ad884bcfbe54d4aa78338031: Scheduling FlushDeltaMemStoresOp(5bb2dbb4a7f6472f80f5882afcb194cc): perf score=2.188937
I20260812 06:19:59.502728  3802 maintenance_manager.cc:643] P b86b9914ad884bcfbe54d4aa78338031: FlushDeltaMemStoresOp(5bb2dbb4a7f6472f80f5882afcb194cc) complete. Timing: real 0.025s	user 0.014s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5493,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:59.503252  3873 maintenance_manager.cc:419] P b86b9914ad884bcfbe54d4aa78338031: Scheduling MajorDeltaCompactionOp(5bb2dbb4a7f6472f80f5882afcb194cc): perf score=1.000000
I20260812 06:19:59.696071  3802 maintenance_manager.cc:643] P b86b9914ad884bcfbe54d4aa78338031: MajorDeltaCompactionOp(5bb2dbb4a7f6472f80f5882afcb194cc) complete. Timing: real 0.193s	user 0.140s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815685,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":354,"lbm_read_time_us":11513,"lbm_reads_lt_1ms":564,"lbm_write_time_us":32955,"lbm_writes_lt_1ms":543,"mutex_wait_us":73,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10624,"update_count":2500}
I20260812 06:19:59.696741  3873 maintenance_manager.cc:419] P b86b9914ad884bcfbe54d4aa78338031: Scheduling FlushDeltaMemStoresOp(5bb2dbb4a7f6472f80f5882afcb194cc): perf score=14.095187
I20260812 06:19:59.743310  3802 maintenance_manager.cc:643] P b86b9914ad884bcfbe54d4aa78338031: FlushDeltaMemStoresOp(5bb2dbb4a7f6472f80f5882afcb194cc) complete. Timing: real 0.046s	user 0.033s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20371,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:59.743830  3873 maintenance_manager.cc:419] P b86b9914ad884bcfbe54d4aa78338031: Scheduling FlushDeltaMemStoresOp(5bb2dbb4a7f6472f80f5882afcb194cc): perf score=2.188937
I20260812 06:19:59.760344  3802 maintenance_manager.cc:643] P b86b9914ad884bcfbe54d4aa78338031: FlushDeltaMemStoresOp(5bb2dbb4a7f6472f80f5882afcb194cc) complete. Timing: real 0.016s	user 0.011s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6337,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:59.760885  3873 maintenance_manager.cc:419] P b86b9914ad884bcfbe54d4aa78338031: Scheduling MajorDeltaCompactionOp(5bb2dbb4a7f6472f80f5882afcb194cc): perf score=1.000000
I20260812 06:19:59.911824  3802 maintenance_manager.cc:643] P b86b9914ad884bcfbe54d4aa78338031: MajorDeltaCompactionOp(5bb2dbb4a7f6472f80f5882afcb194cc) complete. Timing: real 0.151s	user 0.103s	sys 0.045s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":955,"lbm_read_time_us":9003,"lbm_reads_lt_1ms":564,"lbm_write_time_us":27174,"lbm_writes_lt_1ms":543,"mutex_wait_us":28,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":69632,"update_count":2500}
I20260812 06:19:59.912458  3873 maintenance_manager.cc:419] P b86b9914ad884bcfbe54d4aa78338031: Scheduling FlushDeltaMemStoresOp(5bb2dbb4a7f6472f80f5882afcb194cc): perf score=14.095187
I20260812 06:19:59.962900  3802 maintenance_manager.cc:643] P b86b9914ad884bcfbe54d4aa78338031: FlushDeltaMemStoresOp(5bb2dbb4a7f6472f80f5882afcb194cc) complete. Timing: real 0.050s	user 0.036s	sys 0.011s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21697,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:59.963516  3873 maintenance_manager.cc:419] P b86b9914ad884bcfbe54d4aa78338031: Scheduling FlushDeltaMemStoresOp(5bb2dbb4a7f6472f80f5882afcb194cc): perf score=2.188937
I20260812 06:19:59.974650  3802 maintenance_manager.cc:643] P b86b9914ad884bcfbe54d4aa78338031: FlushDeltaMemStoresOp(5bb2dbb4a7f6472f80f5882afcb194cc) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4228,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:59.975154  3873 maintenance_manager.cc:419] P b86b9914ad884bcfbe54d4aa78338031: Scheduling FlushMRSOp(5bb2dbb4a7f6472f80f5882afcb194cc): perf score=1.000000
I20260812 06:20:00.005388  3802 maintenance_manager.cc:643] P b86b9914ad884bcfbe54d4aa78338031: FlushMRSOp(5bb2dbb4a7f6472f80f5882afcb194cc) complete. Timing: real 0.030s	user 0.026s	sys 0.004s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":69,"dirs.run_cpu_time_us":268,"dirs.run_wall_time_us":1562,"drs_written":1,"lbm_read_time_us":40,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1951,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:20:00.006026  3873 maintenance_manager.cc:419] P b86b9914ad884bcfbe54d4aa78338031: Scheduling LogGCOp(5bb2dbb4a7f6472f80f5882afcb194cc): free 121006426 bytes of WAL
I20260812 06:20:00.006297  3802 log_reader.cc:385] T 5bb2dbb4a7f6472f80f5882afcb194cc: removed 12 log segments from log reader
I20260812 06:20:00.006341  3802 log.cc:1079] T 5bb2dbb4a7f6472f80f5882afcb194cc P b86b9914ad884bcfbe54d4aa78338031: Deleting log segment in path: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515592857258-3463-0/minicluster-data/ts-0-root/wals/5bb2dbb4a7f6472f80f5882afcb194cc/wal-000000003 (ops 12-16)
I20260812 06:20:00.006371  3802 log.cc:1079] T 5bb2dbb4a7f6472f80f5882afcb194cc P b86b9914ad884bcfbe54d4aa78338031: Deleting log segment in path: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515592857258-3463-0/minicluster-data/ts-0-root/wals/5bb2dbb4a7f6472f80f5882afcb194cc/wal-000000004 (ops 17-21)
I20260812 06:20:00.006438  3802 log.cc:1079] T 5bb2dbb4a7f6472f80f5882afcb194cc P b86b9914ad884bcfbe54d4aa78338031: Deleting log segment in path: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515592857258-3463-0/minicluster-data/ts-0-root/wals/5bb2dbb4a7f6472f80f5882afcb194cc/wal-000000005 (ops 22-26)
I20260812 06:20:00.006484  3802 log.cc:1079] T 5bb2dbb4a7f6472f80f5882afcb194cc P b86b9914ad884bcfbe54d4aa78338031: Deleting log segment in path: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515592857258-3463-0/minicluster-data/ts-0-root/wals/5bb2dbb4a7f6472f80f5882afcb194cc/wal-000000006 (ops 27-31)
I20260812 06:20:00.006533  3802 log.cc:1079] T 5bb2dbb4a7f6472f80f5882afcb194cc P b86b9914ad884bcfbe54d4aa78338031: Deleting log segment in path: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515592857258-3463-0/minicluster-data/ts-0-root/wals/5bb2dbb4a7f6472f80f5882afcb194cc/wal-000000007 (ops 32-36)
I20260812 06:20:00.006592  3802 log.cc:1079] T 5bb2dbb4a7f6472f80f5882afcb194cc P b86b9914ad884bcfbe54d4aa78338031: Deleting log segment in path: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515592857258-3463-0/minicluster-data/ts-0-root/wals/5bb2dbb4a7f6472f80f5882afcb194cc/wal-000000008 (ops 37-40)
I20260812 06:20:00.006634  3802 log.cc:1079] T 5bb2dbb4a7f6472f80f5882afcb194cc P b86b9914ad884bcfbe54d4aa78338031: Deleting log segment in path: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515592857258-3463-0/minicluster-data/ts-0-root/wals/5bb2dbb4a7f6472f80f5882afcb194cc/wal-000000009 (ops 41-45)
I20260812 06:20:00.006706  3802 log.cc:1079] T 5bb2dbb4a7f6472f80f5882afcb194cc P b86b9914ad884bcfbe54d4aa78338031: Deleting log segment in path: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515592857258-3463-0/minicluster-data/ts-0-root/wals/5bb2dbb4a7f6472f80f5882afcb194cc/wal-000000010 (ops 46-50)
I20260812 06:20:00.006747  3802 log.cc:1079] T 5bb2dbb4a7f6472f80f5882afcb194cc P b86b9914ad884bcfbe54d4aa78338031: Deleting log segment in path: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515592857258-3463-0/minicluster-data/ts-0-root/wals/5bb2dbb4a7f6472f80f5882afcb194cc/wal-000000011 (ops 51-55)
I20260812 06:20:00.006798  3802 log.cc:1079] T 5bb2dbb4a7f6472f80f5882afcb194cc P b86b9914ad884bcfbe54d4aa78338031: Deleting log segment in path: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515592857258-3463-0/minicluster-data/ts-0-root/wals/5bb2dbb4a7f6472f80f5882afcb194cc/wal-000000012 (ops 56-60)
I20260812 06:20:00.006881  3802 log.cc:1079] T 5bb2dbb4a7f6472f80f5882afcb194cc P b86b9914ad884bcfbe54d4aa78338031: Deleting log segment in path: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515592857258-3463-0/minicluster-data/ts-0-root/wals/5bb2dbb4a7f6472f80f5882afcb194cc/wal-000000013 (ops 61-65)
I20260812 06:20:00.006925  3802 log.cc:1079] T 5bb2dbb4a7f6472f80f5882afcb194cc P b86b9914ad884bcfbe54d4aa78338031: Deleting log segment in path: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515592857258-3463-0/minicluster-data/ts-0-root/wals/5bb2dbb4a7f6472f80f5882afcb194cc/wal-000000014 (ops 66-70)
I20260812 06:20:00.033517  3802 maintenance_manager.cc:643] P b86b9914ad884bcfbe54d4aa78338031: LogGCOp(5bb2dbb4a7f6472f80f5882afcb194cc) complete. Timing: real 0.027s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:20:00.033937  3873 maintenance_manager.cc:419] P b86b9914ad884bcfbe54d4aa78338031: Scheduling UndoDeltaBlockGCOp(5bb2dbb4a7f6472f80f5882afcb194cc): 462 bytes on disk
I20260812 06:20:00.034641  3802 maintenance_manager.cc:643] P b86b9914ad884bcfbe54d4aa78338031: UndoDeltaBlockGCOp(5bb2dbb4a7f6472f80f5882afcb194cc) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4}
I20260812 06:20:00.035097  3873 maintenance_manager.cc:419] P b86b9914ad884bcfbe54d4aa78338031: Scheduling FlushDeltaMemStoresOp(5bb2dbb4a7f6472f80f5882afcb194cc): perf score=3.181125
I20260812 06:20:00.058900  3802 maintenance_manager.cc:643] P b86b9914ad884bcfbe54d4aa78338031: FlushDeltaMemStoresOp(5bb2dbb4a7f6472f80f5882afcb194cc) complete. Timing: real 0.024s	user 0.009s	sys 0.011s Metrics: {"bytes_written":4471875,"delete_count":0,"lbm_write_time_us":4519,"lbm_writes_lt_1ms":112,"reinsert_count":0,"update_count":545}
I20260812 06:20:00.059396  3873 maintenance_manager.cc:419] P b86b9914ad884bcfbe54d4aa78338031: Scheduling FlushDeltaMemStoresOp(5bb2dbb4a7f6472f80f5882afcb194cc): perf score=2.188937
I20260812 06:20:00.069324  3802 maintenance_manager.cc:643] P b86b9914ad884bcfbe54d4aa78338031: FlushDeltaMemStoresOp(5bb2dbb4a7f6472f80f5882afcb194cc) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":3733434,"delete_count":0,"lbm_write_time_us":3825,"lbm_writes_lt_1ms":94,"reinsert_count":0,"update_count":455}
I20260812 06:20:00.069795  3873 maintenance_manager.cc:419] P b86b9914ad884bcfbe54d4aa78338031: Scheduling MajorDeltaCompactionOp(5bb2dbb4a7f6472f80f5882afcb194cc): perf score=1.000000
I20260812 06:20:00.336226  3802 maintenance_manager.cc:643] P b86b9914ad884bcfbe54d4aa78338031: MajorDeltaCompactionOp(5bb2dbb4a7f6472f80f5882afcb194cc) complete. Timing: real 0.266s	user 0.166s	sys 0.088s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020737,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":539,"lbm_read_time_us":14886,"lbm_reads_lt_1ms":774,"lbm_write_time_us":42939,"lbm_writes_lt_1ms":743,"mutex_wait_us":28,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":140416,"thread_start_us":103,"threads_started":1,"update_count":3500}
I20260812 06:20:00.337057  3873 maintenance_manager.cc:419] P b86b9914ad884bcfbe54d4aa78338031: Scheduling FlushDeltaMemStoresOp(5bb2dbb4a7f6472f80f5882afcb194cc): perf score=18.063937
I20260812 06:20:00.404412  3802 maintenance_manager.cc:643] P b86b9914ad884bcfbe54d4aa78338031: FlushDeltaMemStoresOp(5bb2dbb4a7f6472f80f5882afcb194cc) complete. Timing: real 0.067s	user 0.031s	sys 0.017s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":23021,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:00.404891  3873 maintenance_manager.cc:419] P b86b9914ad884bcfbe54d4aa78338031: Scheduling FlushDeltaMemStoresOp(5bb2dbb4a7f6472f80f5882afcb194cc): perf score=2.188937
I20260812 06:20:00.416836  3802 maintenance_manager.cc:643] P b86b9914ad884bcfbe54d4aa78338031: FlushDeltaMemStoresOp(5bb2dbb4a7f6472f80f5882afcb194cc) complete. Timing: real 0.012s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4079,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:00.417605  3873 maintenance_manager.cc:419] P b86b9914ad884bcfbe54d4aa78338031: Scheduling MajorDeltaCompactionOp(5bb2dbb4a7f6472f80f5882afcb194cc): perf score=1.000000
I20260812 06:20:00.640661  3802 maintenance_manager.cc:643] P b86b9914ad884bcfbe54d4aa78338031: MajorDeltaCompactionOp(5bb2dbb4a7f6472f80f5882afcb194cc) complete. Timing: real 0.223s	user 0.146s	sys 0.065s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918098,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1840,"lbm_read_time_us":14707,"lbm_reads_lt_1ms":672,"lbm_write_time_us":32882,"lbm_writes_lt_1ms":643,"mutex_wait_us":523,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":3000}
I20260812 06:20:00.641430  3873 maintenance_manager.cc:419] P b86b9914ad884bcfbe54d4aa78338031: Scheduling FlushDeltaMemStoresOp(5bb2dbb4a7f6472f80f5882afcb194cc): perf score=18.063937
I20260812 06:20:00.707990  3802 maintenance_manager.cc:643] P b86b9914ad884bcfbe54d4aa78338031: FlushDeltaMemStoresOp(5bb2dbb4a7f6472f80f5882afcb194cc) complete. Timing: real 0.066s	user 0.026s	sys 0.026s Metrics: {"bytes_written":20512318,"delete_count":0,"lbm_write_time_us":25092,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:00.708451  3873 maintenance_manager.cc:419] P b86b9914ad884bcfbe54d4aa78338031: Scheduling FlushDeltaMemStoresOp(5bb2dbb4a7f6472f80f5882afcb194cc): perf score=2.188937
I20260812 06:20:00.721006  3802 maintenance_manager.cc:643] P b86b9914ad884bcfbe54d4aa78338031: FlushDeltaMemStoresOp(5bb2dbb4a7f6472f80f5882afcb194cc) complete. Timing: real 0.012s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4210,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:00.721617  3873 maintenance_manager.cc:419] P b86b9914ad884bcfbe54d4aa78338031: Scheduling MajorDeltaCompactionOp(5bb2dbb4a7f6472f80f5882afcb194cc): perf score=1.000000
I20260812 06:20:00.933543  3802 maintenance_manager.cc:643] P b86b9914ad884bcfbe54d4aa78338031: MajorDeltaCompactionOp(5bb2dbb4a7f6472f80f5882afcb194cc) complete. Timing: real 0.212s	user 0.155s	sys 0.056s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918100,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":622,"lbm_read_time_us":14553,"lbm_reads_lt_1ms":672,"lbm_write_time_us":37611,"lbm_writes_lt_1ms":643,"mutex_wait_us":92,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":7808,"update_count":3000}
I20260812 06:20:00.934309  3873 maintenance_manager.cc:419] P b86b9914ad884bcfbe54d4aa78338031: Scheduling FlushDeltaMemStoresOp(5bb2dbb4a7f6472f80f5882afcb194cc): perf score=14.095187
I20260812 06:20:00.982892  3802 maintenance_manager.cc:643] P b86b9914ad884bcfbe54d4aa78338031: FlushDeltaMemStoresOp(5bb2dbb4a7f6472f80f5882afcb194cc) complete. Timing: real 0.048s	user 0.031s	sys 0.016s Metrics: {"bytes_written":16409897,"delete_count":0,"lbm_write_time_us":21179,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:00.983392  3873 maintenance_manager.cc:419] P b86b9914ad884bcfbe54d4aa78338031: Scheduling FlushDeltaMemStoresOp(5bb2dbb4a7f6472f80f5882afcb194cc): perf score=2.188937
I20260812 06:20:01.007879  3802 maintenance_manager.cc:643] P b86b9914ad884bcfbe54d4aa78338031: FlushDeltaMemStoresOp(5bb2dbb4a7f6472f80f5882afcb194cc) complete. Timing: real 0.024s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5416,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:01.008345  3873 maintenance_manager.cc:419] P b86b9914ad884bcfbe54d4aa78338031: Scheduling FlushDeltaMemStoresOp(5bb2dbb4a7f6472f80f5882afcb194cc): perf score=2.188937
I20260812 06:20:01.018939  3802 maintenance_manager.cc:643] P b86b9914ad884bcfbe54d4aa78338031: FlushDeltaMemStoresOp(5bb2dbb4a7f6472f80f5882afcb194cc) complete. Timing: real 0.010s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4096,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:01.019383  3873 maintenance_manager.cc:419] P b86b9914ad884bcfbe54d4aa78338031: Scheduling MajorDeltaCompactionOp(5bb2dbb4a7f6472f80f5882afcb194cc): perf score=1.000000
I20260812 06:20:01.222995  3802 maintenance_manager.cc:643] P b86b9914ad884bcfbe54d4aa78338031: MajorDeltaCompactionOp(5bb2dbb4a7f6472f80f5882afcb194cc) complete. Timing: real 0.203s	user 0.130s	sys 0.071s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918210,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":847,"lbm_read_time_us":14410,"lbm_reads_lt_1ms":673,"lbm_write_time_us":34802,"lbm_writes_lt_1ms":643,"mutex_wait_us":161,"peak_mem_usage":75542472,"reinsert_count":0,"update_count":3000}
I20260812 06:20:01.223755  3873 maintenance_manager.cc:419] P b86b9914ad884bcfbe54d4aa78338031: Scheduling FlushDeltaMemStoresOp(5bb2dbb4a7f6472f80f5882afcb194cc): perf score=16.079562
I20260812 06:20:01.279042  3802 maintenance_manager.cc:643] P b86b9914ad884bcfbe54d4aa78338031: FlushDeltaMemStoresOp(5bb2dbb4a7f6472f80f5882afcb194cc) complete. Timing: real 0.055s	user 0.029s	sys 0.020s Metrics: {"bytes_written":17722675,"delete_count":0,"lbm_write_time_us":23204,"lbm_writes_lt_1ms":435,"reinsert_count":0,"update_count":2160}
I20260812 06:20:01.279613  3873 maintenance_manager.cc:419] P b86b9914ad884bcfbe54d4aa78338031: Scheduling FlushDeltaMemStoresOp(5bb2dbb4a7f6472f80f5882afcb194cc): perf score=2.188937
I20260812 06:20:01.295478  3802 maintenance_manager.cc:643] P b86b9914ad884bcfbe54d4aa78338031: FlushDeltaMemStoresOp(5bb2dbb4a7f6472f80f5882afcb194cc) complete. Timing: real 0.016s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3200109,"delete_count":0,"lbm_write_time_us":3388,"lbm_writes_lt_1ms":81,"reinsert_count":0,"update_count":390}
I20260812 06:20:01.296041  3873 maintenance_manager.cc:419] P b86b9914ad884bcfbe54d4aa78338031: Scheduling FlushDeltaMemStoresOp(5bb2dbb4a7f6472f80f5882afcb194cc): perf score=2.188937
I20260812 06:20:01.307447  3802 maintenance_manager.cc:643] P b86b9914ad884bcfbe54d4aa78338031: FlushDeltaMemStoresOp(5bb2dbb4a7f6472f80f5882afcb194cc) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4202,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:01.308144  3873 maintenance_manager.cc:419] P b86b9914ad884bcfbe54d4aa78338031: Scheduling MajorDeltaCompactionOp(5bb2dbb4a7f6472f80f5882afcb194cc): perf score=1.000000
I20260812 06:20:01.535631  3802 maintenance_manager.cc:643] P b86b9914ad884bcfbe54d4aa78338031: MajorDeltaCompactionOp(5bb2dbb4a7f6472f80f5882afcb194cc) complete. Timing: real 0.227s	user 0.167s	sys 0.060s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918184,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":487,"lbm_read_time_us":16903,"lbm_reads_lt_1ms":673,"lbm_write_time_us":40067,"lbm_writes_lt_1ms":643,"mutex_wait_us":93,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":42112,"update_count":3000}
I20260812 06:20:01.536203  3873 maintenance_manager.cc:419] P b86b9914ad884bcfbe54d4aa78338031: Scheduling FlushDeltaMemStoresOp(5bb2dbb4a7f6472f80f5882afcb194cc): perf score=15.087375
I20260812 06:20:01.597271  3802 maintenance_manager.cc:643] P b86b9914ad884bcfbe54d4aa78338031: FlushDeltaMemStoresOp(5bb2dbb4a7f6472f80f5882afcb194cc) complete. Timing: real 0.061s	user 0.043s	sys 0.016s Metrics: {"bytes_written":16820142,"delete_count":0,"lbm_write_time_us":26905,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":411,"reinsert_count":0,"update_count":2050}
I20260812 06:20:01.597759  3873 maintenance_manager.cc:419] P b86b9914ad884bcfbe54d4aa78338031: Scheduling FlushDeltaMemStoresOp(5bb2dbb4a7f6472f80f5882afcb194cc): perf score=2.188937
I20260812 06:20:01.608397  3802 maintenance_manager.cc:643] P b86b9914ad884bcfbe54d4aa78338031: FlushDeltaMemStoresOp(5bb2dbb4a7f6472f80f5882afcb194cc) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4156,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:01.608928  3873 maintenance_manager.cc:419] P b86b9914ad884bcfbe54d4aa78338031: Scheduling FlushDeltaMemStoresOp(5bb2dbb4a7f6472f80f5882afcb194cc): perf score=2.188937
I20260812 06:20:01.618713  3802 maintenance_manager.cc:643] P b86b9914ad884bcfbe54d4aa78338031: FlushDeltaMemStoresOp(5bb2dbb4a7f6472f80f5882afcb194cc) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3588,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:01.619185  3873 maintenance_manager.cc:419] P b86b9914ad884bcfbe54d4aa78338031: Scheduling FlushMRSOp(5bb2dbb4a7f6472f80f5882afcb194cc): perf score=1.000000
I20260812 06:20:01.652809  3802 maintenance_manager.cc:643] P b86b9914ad884bcfbe54d4aa78338031: FlushMRSOp(5bb2dbb4a7f6472f80f5882afcb194cc) complete. Timing: real 0.033s	user 0.031s	sys 0.001s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":67,"dirs.run_cpu_time_us":232,"dirs.run_wall_time_us":1498,"drs_written":1,"lbm_read_time_us":86,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1803,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:20:01.653563  3873 maintenance_manager.cc:419] P b86b9914ad884bcfbe54d4aa78338031: Scheduling LogGCOp(5bb2dbb4a7f6472f80f5882afcb194cc): free 132571338 bytes of WAL
I20260812 06:20:01.653838  3802 log_reader.cc:385] T 5bb2dbb4a7f6472f80f5882afcb194cc: removed 13 log segments from log reader
I20260812 06:20:01.653906  3802 log.cc:1079] T 5bb2dbb4a7f6472f80f5882afcb194cc P b86b9914ad884bcfbe54d4aa78338031: Deleting log segment in path: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515592857258-3463-0/minicluster-data/ts-0-root/wals/5bb2dbb4a7f6472f80f5882afcb194cc/wal-000000015 (ops 71-74)
I20260812 06:20:01.653944  3802 log.cc:1079] T 5bb2dbb4a7f6472f80f5882afcb194cc P b86b9914ad884bcfbe54d4aa78338031: Deleting log segment in path: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515592857258-3463-0/minicluster-data/ts-0-root/wals/5bb2dbb4a7f6472f80f5882afcb194cc/wal-000000016 (ops 75-79)
I20260812 06:20:01.653980  3802 log.cc:1079] T 5bb2dbb4a7f6472f80f5882afcb194cc P b86b9914ad884bcfbe54d4aa78338031: Deleting log segment in path: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515592857258-3463-0/minicluster-data/ts-0-root/wals/5bb2dbb4a7f6472f80f5882afcb194cc/wal-000000017 (ops 80-84)
I20260812 06:20:01.654008  3802 log.cc:1079] T 5bb2dbb4a7f6472f80f5882afcb194cc P b86b9914ad884bcfbe54d4aa78338031: Deleting log segment in path: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515592857258-3463-0/minicluster-data/ts-0-root/wals/5bb2dbb4a7f6472f80f5882afcb194cc/wal-000000018 (ops 85-89)
I20260812 06:20:01.654039  3802 log.cc:1079] T 5bb2dbb4a7f6472f80f5882afcb194cc P b86b9914ad884bcfbe54d4aa78338031: Deleting log segment in path: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515592857258-3463-0/minicluster-data/ts-0-root/wals/5bb2dbb4a7f6472f80f5882afcb194cc/wal-000000019 (ops 90-94)
I20260812 06:20:01.654069  3802 log.cc:1079] T 5bb2dbb4a7f6472f80f5882afcb194cc P b86b9914ad884bcfbe54d4aa78338031: Deleting log segment in path: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515592857258-3463-0/minicluster-data/ts-0-root/wals/5bb2dbb4a7f6472f80f5882afcb194cc/wal-000000020 (ops 95-99)
I20260812 06:20:01.654098  3802 log.cc:1079] T 5bb2dbb4a7f6472f80f5882afcb194cc P b86b9914ad884bcfbe54d4aa78338031: Deleting log segment in path: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515592857258-3463-0/minicluster-data/ts-0-root/wals/5bb2dbb4a7f6472f80f5882afcb194cc/wal-000000021 (ops 100-104)
I20260812 06:20:01.654132  3802 log.cc:1079] T 5bb2dbb4a7f6472f80f5882afcb194cc P b86b9914ad884bcfbe54d4aa78338031: Deleting log segment in path: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515592857258-3463-0/minicluster-data/ts-0-root/wals/5bb2dbb4a7f6472f80f5882afcb194cc/wal-000000022 (ops 105-108)
I20260812 06:20:01.654166  3802 log.cc:1079] T 5bb2dbb4a7f6472f80f5882afcb194cc P b86b9914ad884bcfbe54d4aa78338031: Deleting log segment in path: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515592857258-3463-0/minicluster-data/ts-0-root/wals/5bb2dbb4a7f6472f80f5882afcb194cc/wal-000000023 (ops 109-113)
I20260812 06:20:01.654193  3802 log.cc:1079] T 5bb2dbb4a7f6472f80f5882afcb194cc P b86b9914ad884bcfbe54d4aa78338031: Deleting log segment in path: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515592857258-3463-0/minicluster-data/ts-0-root/wals/5bb2dbb4a7f6472f80f5882afcb194cc/wal-000000024 (ops 114-118)
I20260812 06:20:01.654219  3802 log.cc:1079] T 5bb2dbb4a7f6472f80f5882afcb194cc P b86b9914ad884bcfbe54d4aa78338031: Deleting log segment in path: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515592857258-3463-0/minicluster-data/ts-0-root/wals/5bb2dbb4a7f6472f80f5882afcb194cc/wal-000000025 (ops 119-123)
I20260812 06:20:01.654245  3802 log.cc:1079] T 5bb2dbb4a7f6472f80f5882afcb194cc P b86b9914ad884bcfbe54d4aa78338031: Deleting log segment in path: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515592857258-3463-0/minicluster-data/ts-0-root/wals/5bb2dbb4a7f6472f80f5882afcb194cc/wal-000000026 (ops 124-128)
I20260812 06:20:01.654268  3802 log.cc:1079] T 5bb2dbb4a7f6472f80f5882afcb194cc P b86b9914ad884bcfbe54d4aa78338031: Deleting log segment in path: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515592857258-3463-0/minicluster-data/ts-0-root/wals/5bb2dbb4a7f6472f80f5882afcb194cc/wal-000000027 (ops 129-133)
I20260812 06:20:01.686853  3802 maintenance_manager.cc:643] P b86b9914ad884bcfbe54d4aa78338031: LogGCOp(5bb2dbb4a7f6472f80f5882afcb194cc) complete. Timing: real 0.033s	user 0.000s	sys 0.031s Metrics: {}
I20260812 06:20:01.687422  3873 maintenance_manager.cc:419] P b86b9914ad884bcfbe54d4aa78338031: Scheduling FlushDeltaMemStoresOp(5bb2dbb4a7f6472f80f5882afcb194cc): perf score=2.188937
I20260812 06:20:01.703871  3802 maintenance_manager.cc:643] P b86b9914ad884bcfbe54d4aa78338031: FlushDeltaMemStoresOp(5bb2dbb4a7f6472f80f5882afcb194cc) complete. Timing: real 0.016s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4575,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:01.704375  3873 maintenance_manager.cc:419] P b86b9914ad884bcfbe54d4aa78338031: Scheduling UndoDeltaBlockGCOp(5bb2dbb4a7f6472f80f5882afcb194cc): 492 bytes on disk
I20260812 06:20:01.704782  3802 maintenance_manager.cc:643] P b86b9914ad884bcfbe54d4aa78338031: UndoDeltaBlockGCOp(5bb2dbb4a7f6472f80f5882afcb194cc) 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:20:01.705329  3873 maintenance_manager.cc:419] P b86b9914ad884bcfbe54d4aa78338031: Scheduling FlushDeltaMemStoresOp(5bb2dbb4a7f6472f80f5882afcb194cc): perf score=2.188937
I20260812 06:20:01.716471  3802 maintenance_manager.cc:643] P b86b9914ad884bcfbe54d4aa78338031: FlushDeltaMemStoresOp(5bb2dbb4a7f6472f80f5882afcb194cc) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4417,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:01.716919  3873 maintenance_manager.cc:419] P b86b9914ad884bcfbe54d4aa78338031: Scheduling MajorDeltaCompactionOp(5bb2dbb4a7f6472f80f5882afcb194cc): perf score=1.000000
I20260812 06:20:01.956508  3802 maintenance_manager.cc:643] P b86b9914ad884bcfbe54d4aa78338031: MajorDeltaCompactionOp(5bb2dbb4a7f6472f80f5882afcb194cc) complete. Timing: real 0.239s	user 0.190s	sys 0.047s Metrics: {"cfile_cache_miss":835,"cfile_cache_miss_bytes":37123263,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":629,"lbm_read_time_us":17078,"lbm_reads_lt_1ms":875,"lbm_write_time_us":42873,"lbm_writes_lt_1ms":843,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":12160,"thread_start_us":84,"threads_started":1,"update_count":4000}
I20260812 06:20:01.957326  3873 maintenance_manager.cc:419] P b86b9914ad884bcfbe54d4aa78338031: Scheduling FlushDeltaMemStoresOp(5bb2dbb4a7f6472f80f5882afcb194cc): perf score=18.063937
I20260812 06:20:02.021341  3802 maintenance_manager.cc:643] P b86b9914ad884bcfbe54d4aa78338031: FlushDeltaMemStoresOp(5bb2dbb4a7f6472f80f5882afcb194cc) complete. Timing: real 0.064s	user 0.030s	sys 0.033s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":28607,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:02.021935  3873 maintenance_manager.cc:419] P b86b9914ad884bcfbe54d4aa78338031: Scheduling FlushDeltaMemStoresOp(5bb2dbb4a7f6472f80f5882afcb194cc): perf score=2.188937
I20260812 06:20:02.035966  3802 maintenance_manager.cc:643] P b86b9914ad884bcfbe54d4aa78338031: FlushDeltaMemStoresOp(5bb2dbb4a7f6472f80f5882afcb194cc) complete. Timing: real 0.014s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5273,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:02.036477  3873 maintenance_manager.cc:419] P b86b9914ad884bcfbe54d4aa78338031: Scheduling MajorDeltaCompactionOp(5bb2dbb4a7f6472f80f5882afcb194cc): perf score=1.000000
I20260812 06:20:02.208580  3802 maintenance_manager.cc:643] P b86b9914ad884bcfbe54d4aa78338031: MajorDeltaCompactionOp(5bb2dbb4a7f6472f80f5882afcb194cc) complete. Timing: real 0.172s	user 0.144s	sys 0.027s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918096,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":726,"lbm_read_time_us":12290,"lbm_reads_lt_1ms":672,"lbm_write_time_us":32477,"lbm_writes_lt_1ms":643,"mutex_wait_us":344,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":61440,"update_count":3000}
I20260812 06:20:02.209553  3873 maintenance_manager.cc:419] P b86b9914ad884bcfbe54d4aa78338031: Scheduling FlushDeltaMemStoresOp(5bb2dbb4a7f6472f80f5882afcb194cc): perf score=14.095187
I20260812 06:20:02.267918  3802 maintenance_manager.cc:643] P b86b9914ad884bcfbe54d4aa78338031: FlushDeltaMemStoresOp(5bb2dbb4a7f6472f80f5882afcb194cc) complete. Timing: real 0.058s	user 0.040s	sys 0.015s Metrics: {"bytes_written":16409898,"delete_count":0,"lbm_write_time_us":26514,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:02.268514  3873 maintenance_manager.cc:419] P b86b9914ad884bcfbe54d4aa78338031: Scheduling FlushDeltaMemStoresOp(5bb2dbb4a7f6472f80f5882afcb194cc): perf score=2.188937
I20260812 06:20:02.282919  3802 maintenance_manager.cc:643] P b86b9914ad884bcfbe54d4aa78338031: FlushDeltaMemStoresOp(5bb2dbb4a7f6472f80f5882afcb194cc) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5528,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:02.283475  3873 maintenance_manager.cc:419] P b86b9914ad884bcfbe54d4aa78338031: Scheduling MajorDeltaCompactionOp(5bb2dbb4a7f6472f80f5882afcb194cc): perf score=1.000000
I20260812 06:20:02.452700  3802 maintenance_manager.cc:643] P b86b9914ad884bcfbe54d4aa78338031: MajorDeltaCompactionOp(5bb2dbb4a7f6472f80f5882afcb194cc) complete. Timing: real 0.169s	user 0.131s	sys 0.037s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815680,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":656,"lbm_read_time_us":11206,"lbm_reads_lt_1ms":564,"lbm_write_time_us":33211,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:20:02.453402  3873 maintenance_manager.cc:419] P b86b9914ad884bcfbe54d4aa78338031: Scheduling FlushDeltaMemStoresOp(5bb2dbb4a7f6472f80f5882afcb194cc): perf score=14.095187
I20260812 06:20:02.525395  3802 maintenance_manager.cc:643] P b86b9914ad884bcfbe54d4aa78338031: FlushDeltaMemStoresOp(5bb2dbb4a7f6472f80f5882afcb194cc) complete. Timing: real 0.072s	user 0.037s	sys 0.029s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":33821,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":400,"mutex_wait_us":1,"reinsert_count":0,"update_count":2000}
I20260812 06:20:02.525943  3873 maintenance_manager.cc:419] P b86b9914ad884bcfbe54d4aa78338031: Scheduling FlushDeltaMemStoresOp(5bb2dbb4a7f6472f80f5882afcb194cc): perf score=2.188937
I20260812 06:20:02.536363  3802 maintenance_manager.cc:643] P b86b9914ad884bcfbe54d4aa78338031: FlushDeltaMemStoresOp(5bb2dbb4a7f6472f80f5882afcb194cc) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3886,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:02.536865  3873 maintenance_manager.cc:419] P b86b9914ad884bcfbe54d4aa78338031: Scheduling MajorDeltaCompactionOp(5bb2dbb4a7f6472f80f5882afcb194cc): perf score=1.000000
I20260812 06:20:02.731184  3802 maintenance_manager.cc:643] P b86b9914ad884bcfbe54d4aa78338031: MajorDeltaCompactionOp(5bb2dbb4a7f6472f80f5882afcb194cc) complete. Timing: real 0.194s	user 0.126s	sys 0.065s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":198,"lbm_read_time_us":14006,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32744,"lbm_writes_lt_1ms":543,"mutex_wait_us":21,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":16512,"update_count":2500}
I20260812 06:20:02.731823  3873 maintenance_manager.cc:419] P b86b9914ad884bcfbe54d4aa78338031: Scheduling FlushDeltaMemStoresOp(5bb2dbb4a7f6472f80f5882afcb194cc): perf score=14.095187
I20260812 06:20:02.788878  3802 maintenance_manager.cc:643] P b86b9914ad884bcfbe54d4aa78338031: FlushDeltaMemStoresOp(5bb2dbb4a7f6472f80f5882afcb194cc) complete. Timing: real 0.057s	user 0.028s	sys 0.024s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":22640,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:02.789515  3873 maintenance_manager.cc:419] P b86b9914ad884bcfbe54d4aa78338031: Scheduling FlushDeltaMemStoresOp(5bb2dbb4a7f6472f80f5882afcb194cc): perf score=2.188937
I20260812 06:20:02.807067  3802 maintenance_manager.cc:643] P b86b9914ad884bcfbe54d4aa78338031: FlushDeltaMemStoresOp(5bb2dbb4a7f6472f80f5882afcb194cc) complete. Timing: real 0.017s	user 0.011s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6863,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:02.807715  3873 maintenance_manager.cc:419] P b86b9914ad884bcfbe54d4aa78338031: Scheduling MajorDeltaCompactionOp(5bb2dbb4a7f6472f80f5882afcb194cc): perf score=1.000000
I20260812 06:20:02.977346  3802 maintenance_manager.cc:643] P b86b9914ad884bcfbe54d4aa78338031: MajorDeltaCompactionOp(5bb2dbb4a7f6472f80f5882afcb194cc) complete. Timing: real 0.169s	user 0.112s	sys 0.055s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815686,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":2091,"lbm_read_time_us":11628,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28217,"lbm_writes_lt_1ms":543,"mutex_wait_us":1652,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":2500}
I20260812 06:20:02.977955  3873 maintenance_manager.cc:419] P b86b9914ad884bcfbe54d4aa78338031: Scheduling FlushDeltaMemStoresOp(5bb2dbb4a7f6472f80f5882afcb194cc): perf score=14.095187
I20260812 06:20:03.035643  3802 maintenance_manager.cc:643] P b86b9914ad884bcfbe54d4aa78338031: FlushDeltaMemStoresOp(5bb2dbb4a7f6472f80f5882afcb194cc) complete. Timing: real 0.058s	user 0.031s	sys 0.024s Metrics: {"bytes_written":16409898,"delete_count":0,"lbm_write_time_us":22217,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:03.036284  3873 maintenance_manager.cc:419] P b86b9914ad884bcfbe54d4aa78338031: Scheduling FlushDeltaMemStoresOp(5bb2dbb4a7f6472f80f5882afcb194cc): perf score=2.188937
I20260812 06:20:03.047720  3802 maintenance_manager.cc:643] P b86b9914ad884bcfbe54d4aa78338031: FlushDeltaMemStoresOp(5bb2dbb4a7f6472f80f5882afcb194cc) complete. Timing: real 0.011s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4618,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:03.048247  3873 maintenance_manager.cc:419] P b86b9914ad884bcfbe54d4aa78338031: Scheduling FlushMRSOp(5bb2dbb4a7f6472f80f5882afcb194cc): perf score=1.000000
I20260812 06:20:03.088862  3802 maintenance_manager.cc:643] P b86b9914ad884bcfbe54d4aa78338031: FlushMRSOp(5bb2dbb4a7f6472f80f5882afcb194cc) complete. Timing: real 0.040s	user 0.032s	sys 0.000s Metrics: {"bytes_written":1152512,"cfile_init":1,"dirs.queue_time_us":68,"dirs.run_cpu_time_us":274,"dirs.run_wall_time_us":1403,"drs_written":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1533,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:20:03.089825  3873 maintenance_manager.cc:419] P b86b9914ad884bcfbe54d4aa78338031: Scheduling LogGCOp(5bb2dbb4a7f6472f80f5882afcb194cc): free 112239554 bytes of WAL
I20260812 06:20:03.090142  3802 log_reader.cc:385] T 5bb2dbb4a7f6472f80f5882afcb194cc: removed 11 log segments from log reader
I20260812 06:20:03.090210  3802 log.cc:1079] T 5bb2dbb4a7f6472f80f5882afcb194cc P b86b9914ad884bcfbe54d4aa78338031: Deleting log segment in path: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515592857258-3463-0/minicluster-data/ts-0-root/wals/5bb2dbb4a7f6472f80f5882afcb194cc/wal-000000028 (ops 134-138)
I20260812 06:20:03.090258  3802 log.cc:1079] T 5bb2dbb4a7f6472f80f5882afcb194cc P b86b9914ad884bcfbe54d4aa78338031: Deleting log segment in path: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515592857258-3463-0/minicluster-data/ts-0-root/wals/5bb2dbb4a7f6472f80f5882afcb194cc/wal-000000029 (ops 139-143)
I20260812 06:20:03.090297  3802 log.cc:1079] T 5bb2dbb4a7f6472f80f5882afcb194cc P b86b9914ad884bcfbe54d4aa78338031: Deleting log segment in path: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515592857258-3463-0/minicluster-data/ts-0-root/wals/5bb2dbb4a7f6472f80f5882afcb194cc/wal-000000030 (ops 144-148)
I20260812 06:20:03.090335  3802 log.cc:1079] T 5bb2dbb4a7f6472f80f5882afcb194cc P b86b9914ad884bcfbe54d4aa78338031: Deleting log segment in path: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515592857258-3463-0/minicluster-data/ts-0-root/wals/5bb2dbb4a7f6472f80f5882afcb194cc/wal-000000031 (ops 149-152)
I20260812 06:20:03.090376  3802 log.cc:1079] T 5bb2dbb4a7f6472f80f5882afcb194cc P b86b9914ad884bcfbe54d4aa78338031: Deleting log segment in path: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515592857258-3463-0/minicluster-data/ts-0-root/wals/5bb2dbb4a7f6472f80f5882afcb194cc/wal-000000032 (ops 153-157)
I20260812 06:20:03.090407  3802 log.cc:1079] T 5bb2dbb4a7f6472f80f5882afcb194cc P b86b9914ad884bcfbe54d4aa78338031: Deleting log segment in path: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515592857258-3463-0/minicluster-data/ts-0-root/wals/5bb2dbb4a7f6472f80f5882afcb194cc/wal-000000033 (ops 158-162)
I20260812 06:20:03.090444  3802 log.cc:1079] T 5bb2dbb4a7f6472f80f5882afcb194cc P b86b9914ad884bcfbe54d4aa78338031: Deleting log segment in path: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515592857258-3463-0/minicluster-data/ts-0-root/wals/5bb2dbb4a7f6472f80f5882afcb194cc/wal-000000034 (ops 163-167)
I20260812 06:20:03.090482  3802 log.cc:1079] T 5bb2dbb4a7f6472f80f5882afcb194cc P b86b9914ad884bcfbe54d4aa78338031: Deleting log segment in path: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515592857258-3463-0/minicluster-data/ts-0-root/wals/5bb2dbb4a7f6472f80f5882afcb194cc/wal-000000035 (ops 168-172)
I20260812 06:20:03.090521  3802 log.cc:1079] T 5bb2dbb4a7f6472f80f5882afcb194cc P b86b9914ad884bcfbe54d4aa78338031: Deleting log segment in path: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515592857258-3463-0/minicluster-data/ts-0-root/wals/5bb2dbb4a7f6472f80f5882afcb194cc/wal-000000036 (ops 173-177)
I20260812 06:20:03.090561  3802 log.cc:1079] T 5bb2dbb4a7f6472f80f5882afcb194cc P b86b9914ad884bcfbe54d4aa78338031: Deleting log segment in path: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515592857258-3463-0/minicluster-data/ts-0-root/wals/5bb2dbb4a7f6472f80f5882afcb194cc/wal-000000037 (ops 178-182)
I20260812 06:20:03.090600  3802 log.cc:1079] T 5bb2dbb4a7f6472f80f5882afcb194cc P b86b9914ad884bcfbe54d4aa78338031: Deleting log segment in path: /tmp/dist-test-task3hNVyk/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515592857258-3463-0/minicluster-data/ts-0-root/wals/5bb2dbb4a7f6472f80f5882afcb194cc/wal-000000038 (ops 183-187)
I20260812 06:20:03.116192  3802 maintenance_manager.cc:643] P b86b9914ad884bcfbe54d4aa78338031: LogGCOp(5bb2dbb4a7f6472f80f5882afcb194cc) complete. Timing: real 0.026s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:20:03.116715  3873 maintenance_manager.cc:419] P b86b9914ad884bcfbe54d4aa78338031: Scheduling FlushDeltaMemStoresOp(5bb2dbb4a7f6472f80f5882afcb194cc): perf score=2.188937
I20260812 06:20:03.142926  3802 maintenance_manager.cc:643] P b86b9914ad884bcfbe54d4aa78338031: FlushDeltaMemStoresOp(5bb2dbb4a7f6472f80f5882afcb194cc) complete. Timing: real 0.026s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4585,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:03.143564  3873 maintenance_manager.cc:419] P b86b9914ad884bcfbe54d4aa78338031: Scheduling UndoDeltaBlockGCOp(5bb2dbb4a7f6472f80f5882afcb194cc): 447 bytes on disk
I20260812 06:20:03.144009  3802 maintenance_manager.cc:643] P b86b9914ad884bcfbe54d4aa78338031: UndoDeltaBlockGCOp(5bb2dbb4a7f6472f80f5882afcb194cc) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4}
I20260812 06:20:03.144558  3873 maintenance_manager.cc:419] P b86b9914ad884bcfbe54d4aa78338031: Scheduling FlushDeltaMemStoresOp(5bb2dbb4a7f6472f80f5882afcb194cc): perf score=2.188937
I20260812 06:20:03.160171  3802 maintenance_manager.cc:643] P b86b9914ad884bcfbe54d4aa78338031: FlushDeltaMemStoresOp(5bb2dbb4a7f6472f80f5882afcb194cc) complete. Timing: real 0.015s	user 0.006s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5866,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:03.160758  3873 maintenance_manager.cc:419] P b86b9914ad884bcfbe54d4aa78338031: Scheduling MajorDeltaCompactionOp(5bb2dbb4a7f6472f80f5882afcb194cc): perf score=1.000000
I20260812 06:20:03.367426  3463 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.972s	user 1.835s	sys 0.191s
I20260812 06:20:03.405192  3802 maintenance_manager.cc:643] P b86b9914ad884bcfbe54d4aa78338031: MajorDeltaCompactionOp(5bb2dbb4a7f6472f80f5882afcb194cc) complete. Timing: real 0.244s	user 0.193s	sys 0.051s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020742,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"lbm_read_time_us":16999,"lbm_reads_lt_1ms":770,"lbm_write_time_us":42244,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":3500}
I20260812 06:20:03.405982  3873 maintenance_manager.cc:419] P b86b9914ad884bcfbe54d4aa78338031: Scheduling FlushDeltaMemStoresOp(5bb2dbb4a7f6472f80f5882afcb194cc): perf score=14.095187
I20260812 06:20:03.438951  3802 maintenance_manager.cc:643] P b86b9914ad884bcfbe54d4aa78338031: FlushDeltaMemStoresOp(5bb2dbb4a7f6472f80f5882afcb194cc) complete. Timing: real 0.033s	user 0.024s	sys 0.008s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":15973,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:03.439459  3873 maintenance_manager.cc:419] P b86b9914ad884bcfbe54d4aa78338031: Scheduling MajorDeltaCompactionOp(5bb2dbb4a7f6472f80f5882afcb194cc): perf score=1.000000
I20260812 06:20:03.470388  3463 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.103s	user 0.002s	sys 0.000s
I20260812 06:20:03.470934  3463 tablet_server.cc:179] TabletServer@127.3.97.193:0 shutting down...
I20260812 06:20:03.568584  3802 maintenance_manager.cc:643] P b86b9914ad884bcfbe54d4aa78338031: MajorDeltaCompactionOp(5bb2dbb4a7f6472f80f5882afcb194cc) complete. Timing: real 0.129s	user 0.101s	sys 0.028s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713153,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":274,"lbm_read_time_us":9558,"lbm_reads_lt_1ms":467,"lbm_write_time_us":27923,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":442,"mutex_wait_us":61,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10368,"update_count":2000}
I20260812 06:20:03.569317  3463 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:03.569604  3463 tablet_replica.cc:333] T 5bb2dbb4a7f6472f80f5882afcb194cc P b86b9914ad884bcfbe54d4aa78338031: stopping tablet replica
I20260812 06:20:03.569761  3463 raft_consensus.cc:2243] T 5bb2dbb4a7f6472f80f5882afcb194cc P b86b9914ad884bcfbe54d4aa78338031 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:03.569944  3463 raft_consensus.cc:2272] T 5bb2dbb4a7f6472f80f5882afcb194cc P b86b9914ad884bcfbe54d4aa78338031 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:03.584483  3463 tablet_server.cc:196] TabletServer@127.3.97.193:0 shutdown complete.
I20260812 06:20:03.608242  3463 master.cc:562] Master@127.3.97.254:43953 shutting down...
I20260812 06:20:03.612368  3463 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 98c968c46e424a0ead9474d313ebc108 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:03.612571  3463 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 98c968c46e424a0ead9474d313ebc108 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:03.612622  3463 tablet_replica.cc:333] T 00000000000000000000000000000000 P 98c968c46e424a0ead9474d313ebc108: stopping tablet replica
I20260812 06:20:03.625190  3463 master.cc:584] Master@127.3.97.254:43953 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5513 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10846 ms total)

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