[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:18:12.314309 32569 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.31.206.126:33829
I20260812 06:18:12.315176 32569 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:18:12.315672 32569 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:12.321300 32585 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:12.321417 32569 server_base.cc:1061] running on GCE node
W20260812 06:18:12.321521 32583 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:12.321579 32582 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:12.322034 32569 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:12.322146 32569 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:12.322185 32569 hybrid_clock.cc:648] HybridClock initialized: now 1786515492322183 us; error 0 us; skew 500 ppm
I20260812 06:18:12.323695 32569 webserver.cc:533] Webserver started at http://127.31.206.126:44789/ using document root <none> and password file <none>
I20260812 06:18:12.324152 32569 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:12.324211 32569 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:12.324409 32569 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:12.325897 32569 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515492304271-32569-0/minicluster-data/master-0-root/instance:
uuid: "6470be5713f34aa6b71006b72162cbe0"
format_stamp: "Formatted at 2026-08-12 06:18:12 on dist-test-slave-q9h9"
I20260812 06:18:12.329094 32569 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:18:12.330910 32598 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:12.331786 32569 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:18:12.331883 32569 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515492304271-32569-0/minicluster-data/master-0-root
uuid: "6470be5713f34aa6b71006b72162cbe0"
format_stamp: "Formatted at 2026-08-12 06:18:12 on dist-test-slave-q9h9"
I20260812 06:18:12.331960 32569 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515492304271-32569-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515492304271-32569-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515492304271-32569-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:12.361778 32569 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:12.362277 32569 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:18:12.362407 32569 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:12.369059 32569 rpc_server.cc:307] RPC server started. Bound to: 127.31.206.126:33829
I20260812 06:18:12.369076 32708 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.31.206.126:33829 every 8 connection(s)
I20260812 06:18:12.371133 32709 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:12.376083 32709 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 6470be5713f34aa6b71006b72162cbe0: Bootstrap starting.
I20260812 06:18:12.378286 32709 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 6470be5713f34aa6b71006b72162cbe0: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:12.379077 32709 log.cc:826] T 00000000000000000000000000000000 P 6470be5713f34aa6b71006b72162cbe0: Log is configured to *not* fsync() on all Append() calls
I20260812 06:18:12.380617 32709 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 6470be5713f34aa6b71006b72162cbe0: No bootstrap required, opened a new log
I20260812 06:18:12.383209 32709 raft_consensus.cc:359] T 00000000000000000000000000000000 P 6470be5713f34aa6b71006b72162cbe0 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6470be5713f34aa6b71006b72162cbe0" member_type: VOTER }
I20260812 06:18:12.383352 32709 raft_consensus.cc:385] T 00000000000000000000000000000000 P 6470be5713f34aa6b71006b72162cbe0 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:12.383415 32709 raft_consensus.cc:740] T 00000000000000000000000000000000 P 6470be5713f34aa6b71006b72162cbe0 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 6470be5713f34aa6b71006b72162cbe0, State: Initialized, Role: FOLLOWER
I20260812 06:18:12.383915 32709 consensus_queue.cc:260] T 00000000000000000000000000000000 P 6470be5713f34aa6b71006b72162cbe0 [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: "6470be5713f34aa6b71006b72162cbe0" member_type: VOTER }
I20260812 06:18:12.384054 32709 raft_consensus.cc:399] T 00000000000000000000000000000000 P 6470be5713f34aa6b71006b72162cbe0 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:12.384125 32709 raft_consensus.cc:493] T 00000000000000000000000000000000 P 6470be5713f34aa6b71006b72162cbe0 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:12.384241 32709 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 6470be5713f34aa6b71006b72162cbe0 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:12.384917 32709 raft_consensus.cc:515] T 00000000000000000000000000000000 P 6470be5713f34aa6b71006b72162cbe0 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6470be5713f34aa6b71006b72162cbe0" member_type: VOTER }
I20260812 06:18:12.385303 32709 leader_election.cc:304] T 00000000000000000000000000000000 P 6470be5713f34aa6b71006b72162cbe0 [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: 6470be5713f34aa6b71006b72162cbe0; no voters: 
I20260812 06:18:12.385587 32709 leader_election.cc:290] T 00000000000000000000000000000000 P 6470be5713f34aa6b71006b72162cbe0 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:12.385684 32716 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 6470be5713f34aa6b71006b72162cbe0 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:12.385887 32716 raft_consensus.cc:697] T 00000000000000000000000000000000 P 6470be5713f34aa6b71006b72162cbe0 [term 1 LEADER]: Becoming Leader. State: Replica: 6470be5713f34aa6b71006b72162cbe0, State: Running, Role: LEADER
I20260812 06:18:12.386276 32716 consensus_queue.cc:237] T 00000000000000000000000000000000 P 6470be5713f34aa6b71006b72162cbe0 [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: "6470be5713f34aa6b71006b72162cbe0" member_type: VOTER }
I20260812 06:18:12.386468 32709 sys_catalog.cc:565] T 00000000000000000000000000000000 P 6470be5713f34aa6b71006b72162cbe0 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:12.387952 32720 sys_catalog.cc:455] T 00000000000000000000000000000000 P 6470be5713f34aa6b71006b72162cbe0 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 6470be5713f34aa6b71006b72162cbe0. Latest consensus state: current_term: 1 leader_uuid: "6470be5713f34aa6b71006b72162cbe0" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6470be5713f34aa6b71006b72162cbe0" member_type: VOTER } }
I20260812 06:18:12.388089 32720 sys_catalog.cc:458] T 00000000000000000000000000000000 P 6470be5713f34aa6b71006b72162cbe0 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:12.387957 32717 sys_catalog.cc:455] T 00000000000000000000000000000000 P 6470be5713f34aa6b71006b72162cbe0 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "6470be5713f34aa6b71006b72162cbe0" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6470be5713f34aa6b71006b72162cbe0" member_type: VOTER } }
I20260812 06:18:12.388319 32717 sys_catalog.cc:458] T 00000000000000000000000000000000 P 6470be5713f34aa6b71006b72162cbe0 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:12.388410 32736 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:12.388476 32569 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:12.390539 32736 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:12.394371 32736 catalog_manager.cc:1383] Generated new cluster ID: 97d8cdbe15a5402a9bd7877812d32910
I20260812 06:18:12.394428 32736 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:12.398969 32736 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:12.399657 32736 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:12.406313 32736 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 6470be5713f34aa6b71006b72162cbe0: Generated new TSK 0
I20260812 06:18:12.406764 32736 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:12.420831 32569 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:12.423276 32745 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:12.423352 32748 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:12.423492 32750 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:12.423578 32569 server_base.cc:1061] running on GCE node
I20260812 06:18:12.423791 32569 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:12.423835 32569 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:12.423854 32569 hybrid_clock.cc:648] HybridClock initialized: now 1786515492423855 us; error 0 us; skew 500 ppm
I20260812 06:18:12.424624 32569 webserver.cc:533] Webserver started at http://127.31.206.65:44227/ using document root <none> and password file <none>
I20260812 06:18:12.424765 32569 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:12.424811 32569 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:12.424882 32569 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:12.425189 32569 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515492304271-32569-0/minicluster-data/ts-0-root/instance:
uuid: "54f46c4b90af49d0b13d5a48ace08c79"
format_stamp: "Formatted at 2026-08-12 06:18:12 on dist-test-slave-q9h9"
I20260812 06:18:12.426564 32569 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:18:12.427460 32758 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:12.427708 32569 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:12.427770 32569 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515492304271-32569-0/minicluster-data/ts-0-root
uuid: "54f46c4b90af49d0b13d5a48ace08c79"
format_stamp: "Formatted at 2026-08-12 06:18:12 on dist-test-slave-q9h9"
I20260812 06:18:12.427834 32569 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515492304271-32569-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515492304271-32569-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515492304271-32569-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:12.434335 32569 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:12.434646 32569 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:12.435004 32569 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:12.435750 32569 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:12.435802 32569 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:12.435849 32569 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:12.435879 32569 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:12.441532 32569 rpc_server.cc:307] RPC server started. Bound to: 127.31.206.65:45369
I20260812 06:18:12.441561   415 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.31.206.65:45369 every 8 connection(s)
I20260812 06:18:12.456777   416 heartbeater.cc:344] Connected to a master server at 127.31.206.126:33829
I20260812 06:18:12.456964   416 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:12.457321   416 heartbeater.cc:507] Master 127.31.206.126:33829 requested a full tablet report, sending...
I20260812 06:18:12.458565 32628 ts_manager.cc:194] Registered new tserver with Master: 54f46c4b90af49d0b13d5a48ace08c79 (127.31.206.65:45369)
I20260812 06:18:12.458914 32569 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.016831348s
I20260812 06:18:12.459877 32628 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:52206
I20260812 06:18:12.466939 32628 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:52220:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:18:12.479146   347 tablet_service.cc:1511] Processing CreateTablet for tablet 89e5fc3fb4cb44e89efbd7b95ab42c81 (DEFAULT_TABLE table=heavy-update-compaction-test [id=9c7fe0444c64440f90f2021230685fd6]), partition=
I20260812 06:18:12.479507   347 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 89e5fc3fb4cb44e89efbd7b95ab42c81. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:12.481534   443 tablet_bootstrap.cc:492] T 89e5fc3fb4cb44e89efbd7b95ab42c81 P 54f46c4b90af49d0b13d5a48ace08c79: Bootstrap starting.
I20260812 06:18:12.482582   443 tablet_bootstrap.cc:654] T 89e5fc3fb4cb44e89efbd7b95ab42c81 P 54f46c4b90af49d0b13d5a48ace08c79: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:12.483724   443 tablet_bootstrap.cc:492] T 89e5fc3fb4cb44e89efbd7b95ab42c81 P 54f46c4b90af49d0b13d5a48ace08c79: No bootstrap required, opened a new log
I20260812 06:18:12.483817   443 ts_tablet_manager.cc:1403] T 89e5fc3fb4cb44e89efbd7b95ab42c81 P 54f46c4b90af49d0b13d5a48ace08c79: Time spent bootstrapping tablet: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:18:12.484283   443 raft_consensus.cc:359] T 89e5fc3fb4cb44e89efbd7b95ab42c81 P 54f46c4b90af49d0b13d5a48ace08c79 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "54f46c4b90af49d0b13d5a48ace08c79" member_type: VOTER last_known_addr { host: "127.31.206.65" port: 45369 } }
I20260812 06:18:12.484385   443 raft_consensus.cc:385] T 89e5fc3fb4cb44e89efbd7b95ab42c81 P 54f46c4b90af49d0b13d5a48ace08c79 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:12.484423   443 raft_consensus.cc:740] T 89e5fc3fb4cb44e89efbd7b95ab42c81 P 54f46c4b90af49d0b13d5a48ace08c79 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 54f46c4b90af49d0b13d5a48ace08c79, State: Initialized, Role: FOLLOWER
I20260812 06:18:12.484540   443 consensus_queue.cc:260] T 89e5fc3fb4cb44e89efbd7b95ab42c81 P 54f46c4b90af49d0b13d5a48ace08c79 [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: "54f46c4b90af49d0b13d5a48ace08c79" member_type: VOTER last_known_addr { host: "127.31.206.65" port: 45369 } }
I20260812 06:18:12.484632   443 raft_consensus.cc:399] T 89e5fc3fb4cb44e89efbd7b95ab42c81 P 54f46c4b90af49d0b13d5a48ace08c79 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:12.484673   443 raft_consensus.cc:493] T 89e5fc3fb4cb44e89efbd7b95ab42c81 P 54f46c4b90af49d0b13d5a48ace08c79 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:12.484720   443 raft_consensus.cc:3060] T 89e5fc3fb4cb44e89efbd7b95ab42c81 P 54f46c4b90af49d0b13d5a48ace08c79 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:12.485564   443 raft_consensus.cc:515] T 89e5fc3fb4cb44e89efbd7b95ab42c81 P 54f46c4b90af49d0b13d5a48ace08c79 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "54f46c4b90af49d0b13d5a48ace08c79" member_type: VOTER last_known_addr { host: "127.31.206.65" port: 45369 } }
I20260812 06:18:12.485700   443 leader_election.cc:304] T 89e5fc3fb4cb44e89efbd7b95ab42c81 P 54f46c4b90af49d0b13d5a48ace08c79 [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: 54f46c4b90af49d0b13d5a48ace08c79; no voters: 
I20260812 06:18:12.485875   443 leader_election.cc:290] T 89e5fc3fb4cb44e89efbd7b95ab42c81 P 54f46c4b90af49d0b13d5a48ace08c79 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:12.485972   447 raft_consensus.cc:2804] T 89e5fc3fb4cb44e89efbd7b95ab42c81 P 54f46c4b90af49d0b13d5a48ace08c79 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:12.486195   443 ts_tablet_manager.cc:1434] T 89e5fc3fb4cb44e89efbd7b95ab42c81 P 54f46c4b90af49d0b13d5a48ace08c79: Time spent starting tablet: real 0.002s	user 0.000s	sys 0.003s
I20260812 06:18:12.486460   416 heartbeater.cc:499] Master 127.31.206.126:33829 was elected leader, sending a full tablet report...
I20260812 06:18:12.486605   447 raft_consensus.cc:697] T 89e5fc3fb4cb44e89efbd7b95ab42c81 P 54f46c4b90af49d0b13d5a48ace08c79 [term 1 LEADER]: Becoming Leader. State: Replica: 54f46c4b90af49d0b13d5a48ace08c79, State: Running, Role: LEADER
I20260812 06:18:12.486724   447 consensus_queue.cc:237] T 89e5fc3fb4cb44e89efbd7b95ab42c81 P 54f46c4b90af49d0b13d5a48ace08c79 [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: "54f46c4b90af49d0b13d5a48ace08c79" member_type: VOTER last_known_addr { host: "127.31.206.65" port: 45369 } }
I20260812 06:18:12.489060 32628 catalog_manager.cc:5719] T 89e5fc3fb4cb44e89efbd7b95ab42c81 P 54f46c4b90af49d0b13d5a48ace08c79 reported cstate change: term changed from 0 to 1, leader changed from <none> to 54f46c4b90af49d0b13d5a48ace08c79 (127.31.206.65). New cstate: current_term: 1 leader_uuid: "54f46c4b90af49d0b13d5a48ace08c79" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "54f46c4b90af49d0b13d5a48ace08c79" member_type: VOTER last_known_addr { host: "127.31.206.65" port: 45369 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:12.554335 32569 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.061s	user 0.023s	sys 0.007s
I20260812 06:18:12.692584   421 maintenance_manager.cc:419] P 54f46c4b90af49d0b13d5a48ace08c79: Scheduling FlushMRSOp(89e5fc3fb4cb44e89efbd7b95ab42c81): perf score=19.054940
I20260812 06:18:12.848232   302 maintenance_manager.cc:643] P 54f46c4b90af49d0b13d5a48ace08c79: FlushMRSOp(89e5fc3fb4cb44e89efbd7b95ab42c81) complete. Timing: real 0.155s	user 0.123s	sys 0.027s Metrics: {"bytes_written":12307490,"cfile_init":1,"compiler_manager_pool.queue_time_us":191,"delete_count":0,"dirs.queue_time_us":61,"dirs.run_cpu_time_us":191,"dirs.run_wall_time_us":719,"drs_written":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4,"lbm_write_time_us":39012,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"thread_start_us":108,"threads_started":1,"update_count":1500}
I20260812 06:18:12.849423   421 maintenance_manager.cc:419] P 54f46c4b90af49d0b13d5a48ace08c79: Scheduling LogGCOp(89e5fc3fb4cb44e89efbd7b95ab42c81): free 20743880 bytes of WAL
I20260812 06:18:12.849725   302 log_reader.cc:385] T 89e5fc3fb4cb44e89efbd7b95ab42c81: removed 2 log segments from log reader
I20260812 06:18:12.849802   302 log.cc:1079] T 89e5fc3fb4cb44e89efbd7b95ab42c81 P 54f46c4b90af49d0b13d5a48ace08c79: Deleting log segment in path: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515492304271-32569-0/minicluster-data/ts-0-root/wals/89e5fc3fb4cb44e89efbd7b95ab42c81/wal-000000001 (ops 1-6)
I20260812 06:18:12.849871   302 log.cc:1079] T 89e5fc3fb4cb44e89efbd7b95ab42c81 P 54f46c4b90af49d0b13d5a48ace08c79: Deleting log segment in path: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515492304271-32569-0/minicluster-data/ts-0-root/wals/89e5fc3fb4cb44e89efbd7b95ab42c81/wal-000000002 (ops 7-11)
I20260812 06:18:12.855295   302 maintenance_manager.cc:643] P 54f46c4b90af49d0b13d5a48ace08c79: LogGCOp(89e5fc3fb4cb44e89efbd7b95ab42c81) complete. Timing: real 0.006s	user 0.001s	sys 0.003s Metrics: {}
I20260812 06:18:12.855728   421 maintenance_manager.cc:419] P 54f46c4b90af49d0b13d5a48ace08c79: Scheduling FlushDeltaMemStoresOp(89e5fc3fb4cb44e89efbd7b95ab42c81): perf score=2.188937
I20260812 06:18:12.889848   302 maintenance_manager.cc:643] P 54f46c4b90af49d0b13d5a48ace08c79: FlushDeltaMemStoresOp(89e5fc3fb4cb44e89efbd7b95ab42c81) complete. Timing: real 0.034s	user 0.010s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5349,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:12.890386   421 maintenance_manager.cc:419] P 54f46c4b90af49d0b13d5a48ace08c79: Scheduling FlushDeltaMemStoresOp(89e5fc3fb4cb44e89efbd7b95ab42c81): perf score=2.188937
I20260812 06:18:12.899927   302 maintenance_manager.cc:643] P 54f46c4b90af49d0b13d5a48ace08c79: FlushDeltaMemStoresOp(89e5fc3fb4cb44e89efbd7b95ab42c81) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3687,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:12.900272   421 maintenance_manager.cc:419] P 54f46c4b90af49d0b13d5a48ace08c79: Scheduling UndoDeltaBlockGCOp(89e5fc3fb4cb44e89efbd7b95ab42c81): 16411393 bytes on disk
I20260812 06:18:12.900759   302 maintenance_manager.cc:643] P 54f46c4b90af49d0b13d5a48ace08c79: UndoDeltaBlockGCOp(89e5fc3fb4cb44e89efbd7b95ab42c81) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":48,"lbm_reads_lt_1ms":4}
I20260812 06:18:12.901129   421 maintenance_manager.cc:419] P 54f46c4b90af49d0b13d5a48ace08c79: Scheduling MajorDeltaCompactionOp(89e5fc3fb4cb44e89efbd7b95ab42c81): perf score=1.000000
I20260812 06:18:13.066449   302 maintenance_manager.cc:643] P 54f46c4b90af49d0b13d5a48ace08c79: MajorDeltaCompactionOp(89e5fc3fb4cb44e89efbd7b95ab42c81) complete. Timing: real 0.165s	user 0.102s	sys 0.062s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774807,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":499,"lbm_read_time_us":11556,"lbm_reads_lt_1ms":569,"lbm_write_time_us":28504,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"thread_start_us":337,"threads_started":5,"update_count":2500}
I20260812 06:18:13.067019   421 maintenance_manager.cc:419] P 54f46c4b90af49d0b13d5a48ace08c79: Scheduling FlushDeltaMemStoresOp(89e5fc3fb4cb44e89efbd7b95ab42c81): perf score=10.126437
I20260812 06:18:13.106091   302 maintenance_manager.cc:643] P 54f46c4b90af49d0b13d5a48ace08c79: FlushDeltaMemStoresOp(89e5fc3fb4cb44e89efbd7b95ab42c81) complete. Timing: real 0.039s	user 0.008s	sys 0.029s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16169,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:13.106472   421 maintenance_manager.cc:419] P 54f46c4b90af49d0b13d5a48ace08c79: Scheduling FlushDeltaMemStoresOp(89e5fc3fb4cb44e89efbd7b95ab42c81): perf score=2.188937
I20260812 06:18:13.115844   302 maintenance_manager.cc:643] P 54f46c4b90af49d0b13d5a48ace08c79: FlushDeltaMemStoresOp(89e5fc3fb4cb44e89efbd7b95ab42c81) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3802,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:13.116307   421 maintenance_manager.cc:419] P 54f46c4b90af49d0b13d5a48ace08c79: Scheduling MajorDeltaCompactionOp(89e5fc3fb4cb44e89efbd7b95ab42c81): perf score=1.000000
I20260812 06:18:13.240623   302 maintenance_manager.cc:643] P 54f46c4b90af49d0b13d5a48ace08c79: MajorDeltaCompactionOp(89e5fc3fb4cb44e89efbd7b95ab42c81) complete. Timing: real 0.124s	user 0.085s	sys 0.035s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":959,"lbm_read_time_us":10734,"lbm_reads_1-10_ms":1,"lbm_reads_lt_1ms":471,"lbm_write_time_us":23955,"lbm_writes_lt_1ms":443,"mutex_wait_us":275,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2000}
I20260812 06:18:13.241111   421 maintenance_manager.cc:419] P 54f46c4b90af49d0b13d5a48ace08c79: Scheduling FlushDeltaMemStoresOp(89e5fc3fb4cb44e89efbd7b95ab42c81): perf score=10.126437
I20260812 06:18:13.285838   302 maintenance_manager.cc:643] P 54f46c4b90af49d0b13d5a48ace08c79: FlushDeltaMemStoresOp(89e5fc3fb4cb44e89efbd7b95ab42c81) complete. Timing: real 0.045s	user 0.023s	sys 0.007s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14174,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:13.286365   421 maintenance_manager.cc:419] P 54f46c4b90af49d0b13d5a48ace08c79: Scheduling FlushDeltaMemStoresOp(89e5fc3fb4cb44e89efbd7b95ab42c81): perf score=2.188937
I20260812 06:18:13.301122   302 maintenance_manager.cc:643] P 54f46c4b90af49d0b13d5a48ace08c79: FlushDeltaMemStoresOp(89e5fc3fb4cb44e89efbd7b95ab42c81) complete. Timing: real 0.015s	user 0.012s	sys 0.000s 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:18:13.301529   421 maintenance_manager.cc:419] P 54f46c4b90af49d0b13d5a48ace08c79: Scheduling MajorDeltaCompactionOp(89e5fc3fb4cb44e89efbd7b95ab42c81): perf score=1.000000
I20260812 06:18:13.420806   302 maintenance_manager.cc:643] P 54f46c4b90af49d0b13d5a48ace08c79: MajorDeltaCompactionOp(89e5fc3fb4cb44e89efbd7b95ab42c81) complete. Timing: real 0.119s	user 0.102s	sys 0.017s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":649,"lbm_read_time_us":8509,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23581,"lbm_writes_lt_1ms":443,"mutex_wait_us":314,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11648,"update_count":2000}
I20260812 06:18:13.421319   421 maintenance_manager.cc:419] P 54f46c4b90af49d0b13d5a48ace08c79: Scheduling FlushDeltaMemStoresOp(89e5fc3fb4cb44e89efbd7b95ab42c81): perf score=10.126437
I20260812 06:18:13.455425   302 maintenance_manager.cc:643] P 54f46c4b90af49d0b13d5a48ace08c79: FlushDeltaMemStoresOp(89e5fc3fb4cb44e89efbd7b95ab42c81) complete. Timing: real 0.034s	user 0.021s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14586,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:13.455926   421 maintenance_manager.cc:419] P 54f46c4b90af49d0b13d5a48ace08c79: Scheduling FlushDeltaMemStoresOp(89e5fc3fb4cb44e89efbd7b95ab42c81): perf score=2.188937
I20260812 06:18:13.468766   302 maintenance_manager.cc:643] P 54f46c4b90af49d0b13d5a48ace08c79: FlushDeltaMemStoresOp(89e5fc3fb4cb44e89efbd7b95ab42c81) complete. Timing: real 0.013s	user 0.000s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5245,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:13.469154   421 maintenance_manager.cc:419] P 54f46c4b90af49d0b13d5a48ace08c79: Scheduling MajorDeltaCompactionOp(89e5fc3fb4cb44e89efbd7b95ab42c81): perf score=1.000000
I20260812 06:18:13.591461   302 maintenance_manager.cc:643] P 54f46c4b90af49d0b13d5a48ace08c79: MajorDeltaCompactionOp(89e5fc3fb4cb44e89efbd7b95ab42c81) complete. Timing: real 0.122s	user 0.088s	sys 0.034s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":270,"lbm_read_time_us":8840,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24593,"lbm_writes_lt_1ms":443,"mutex_wait_us":40,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4352,"update_count":2000}
I20260812 06:18:13.592015   421 maintenance_manager.cc:419] P 54f46c4b90af49d0b13d5a48ace08c79: Scheduling FlushDeltaMemStoresOp(89e5fc3fb4cb44e89efbd7b95ab42c81): perf score=10.126437
I20260812 06:18:13.633937   302 maintenance_manager.cc:643] P 54f46c4b90af49d0b13d5a48ace08c79: FlushDeltaMemStoresOp(89e5fc3fb4cb44e89efbd7b95ab42c81) complete. Timing: real 0.042s	user 0.020s	sys 0.016s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":12803,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:13.634387   421 maintenance_manager.cc:419] P 54f46c4b90af49d0b13d5a48ace08c79: Scheduling FlushDeltaMemStoresOp(89e5fc3fb4cb44e89efbd7b95ab42c81): perf score=2.188937
I20260812 06:18:13.648764   302 maintenance_manager.cc:643] P 54f46c4b90af49d0b13d5a48ace08c79: FlushDeltaMemStoresOp(89e5fc3fb4cb44e89efbd7b95ab42c81) complete. Timing: real 0.014s	user 0.000s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5536,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:13.649183   421 maintenance_manager.cc:419] P 54f46c4b90af49d0b13d5a48ace08c79: Scheduling MajorDeltaCompactionOp(89e5fc3fb4cb44e89efbd7b95ab42c81): perf score=1.000000
I20260812 06:18:13.788980   302 maintenance_manager.cc:643] P 54f46c4b90af49d0b13d5a48ace08c79: MajorDeltaCompactionOp(89e5fc3fb4cb44e89efbd7b95ab42c81) complete. Timing: real 0.140s	user 0.080s	sys 0.060s 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":281,"lbm_read_time_us":11361,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23779,"lbm_writes_lt_1ms":443,"mutex_wait_us":38,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":2000}
I20260812 06:18:13.789582   421 maintenance_manager.cc:419] P 54f46c4b90af49d0b13d5a48ace08c79: Scheduling FlushDeltaMemStoresOp(89e5fc3fb4cb44e89efbd7b95ab42c81): perf score=10.126437
I20260812 06:18:13.831115   302 maintenance_manager.cc:643] P 54f46c4b90af49d0b13d5a48ace08c79: FlushDeltaMemStoresOp(89e5fc3fb4cb44e89efbd7b95ab42c81) complete. Timing: real 0.041s	user 0.024s	sys 0.007s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13927,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:13.831540   421 maintenance_manager.cc:419] P 54f46c4b90af49d0b13d5a48ace08c79: Scheduling FlushDeltaMemStoresOp(89e5fc3fb4cb44e89efbd7b95ab42c81): perf score=2.188937
I20260812 06:18:13.840996   302 maintenance_manager.cc:643] P 54f46c4b90af49d0b13d5a48ace08c79: FlushDeltaMemStoresOp(89e5fc3fb4cb44e89efbd7b95ab42c81) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3662,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:13.841480   421 maintenance_manager.cc:419] P 54f46c4b90af49d0b13d5a48ace08c79: Scheduling MajorDeltaCompactionOp(89e5fc3fb4cb44e89efbd7b95ab42c81): perf score=1.000000
I20260812 06:18:13.958575   302 maintenance_manager.cc:643] P 54f46c4b90af49d0b13d5a48ace08c79: MajorDeltaCompactionOp(89e5fc3fb4cb44e89efbd7b95ab42c81) complete. Timing: real 0.117s	user 0.096s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":307,"lbm_read_time_us":8012,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21698,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:13.959043   421 maintenance_manager.cc:419] P 54f46c4b90af49d0b13d5a48ace08c79: Scheduling FlushDeltaMemStoresOp(89e5fc3fb4cb44e89efbd7b95ab42c81): perf score=10.126437
I20260812 06:18:13.996011   302 maintenance_manager.cc:643] P 54f46c4b90af49d0b13d5a48ace08c79: FlushDeltaMemStoresOp(89e5fc3fb4cb44e89efbd7b95ab42c81) complete. Timing: real 0.037s	user 0.017s	sys 0.017s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":16539,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:13.996517   421 maintenance_manager.cc:419] P 54f46c4b90af49d0b13d5a48ace08c79: Scheduling FlushDeltaMemStoresOp(89e5fc3fb4cb44e89efbd7b95ab42c81): perf score=2.188937
I20260812 06:18:14.007793   302 maintenance_manager.cc:643] P 54f46c4b90af49d0b13d5a48ace08c79: FlushDeltaMemStoresOp(89e5fc3fb4cb44e89efbd7b95ab42c81) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4329,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:14.008311   421 maintenance_manager.cc:419] P 54f46c4b90af49d0b13d5a48ace08c79: Scheduling FlushMRSOp(89e5fc3fb4cb44e89efbd7b95ab42c81): perf score=1.000000
I20260812 06:18:14.035531   302 maintenance_manager.cc:643] P 54f46c4b90af49d0b13d5a48ace08c79: FlushMRSOp(89e5fc3fb4cb44e89efbd7b95ab42c81) complete. Timing: real 0.027s	user 0.025s	sys 0.000s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":43,"dirs.run_cpu_time_us":156,"dirs.run_wall_time_us":889,"drs_written":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1727,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:18:14.036289   421 maintenance_manager.cc:419] P 54f46c4b90af49d0b13d5a48ace08c79: Scheduling LogGCOp(89e5fc3fb4cb44e89efbd7b95ab42c81): free 120553374 bytes of WAL
I20260812 06:18:14.036509   302 log_reader.cc:385] T 89e5fc3fb4cb44e89efbd7b95ab42c81: removed 12 log segments from log reader
I20260812 06:18:14.036553   302 log.cc:1079] T 89e5fc3fb4cb44e89efbd7b95ab42c81 P 54f46c4b90af49d0b13d5a48ace08c79: Deleting log segment in path: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515492304271-32569-0/minicluster-data/ts-0-root/wals/89e5fc3fb4cb44e89efbd7b95ab42c81/wal-000000003 (ops 12-16)
I20260812 06:18:14.036582   302 log.cc:1079] T 89e5fc3fb4cb44e89efbd7b95ab42c81 P 54f46c4b90af49d0b13d5a48ace08c79: Deleting log segment in path: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515492304271-32569-0/minicluster-data/ts-0-root/wals/89e5fc3fb4cb44e89efbd7b95ab42c81/wal-000000004 (ops 17-20)
I20260812 06:18:14.036612   302 log.cc:1079] T 89e5fc3fb4cb44e89efbd7b95ab42c81 P 54f46c4b90af49d0b13d5a48ace08c79: Deleting log segment in path: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515492304271-32569-0/minicluster-data/ts-0-root/wals/89e5fc3fb4cb44e89efbd7b95ab42c81/wal-000000005 (ops 21-25)
I20260812 06:18:14.036645   302 log.cc:1079] T 89e5fc3fb4cb44e89efbd7b95ab42c81 P 54f46c4b90af49d0b13d5a48ace08c79: Deleting log segment in path: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515492304271-32569-0/minicluster-data/ts-0-root/wals/89e5fc3fb4cb44e89efbd7b95ab42c81/wal-000000006 (ops 26-30)
I20260812 06:18:14.036677   302 log.cc:1079] T 89e5fc3fb4cb44e89efbd7b95ab42c81 P 54f46c4b90af49d0b13d5a48ace08c79: Deleting log segment in path: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515492304271-32569-0/minicluster-data/ts-0-root/wals/89e5fc3fb4cb44e89efbd7b95ab42c81/wal-000000007 (ops 31-35)
I20260812 06:18:14.036708   302 log.cc:1079] T 89e5fc3fb4cb44e89efbd7b95ab42c81 P 54f46c4b90af49d0b13d5a48ace08c79: Deleting log segment in path: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515492304271-32569-0/minicluster-data/ts-0-root/wals/89e5fc3fb4cb44e89efbd7b95ab42c81/wal-000000008 (ops 36-40)
I20260812 06:18:14.036751   302 log.cc:1079] T 89e5fc3fb4cb44e89efbd7b95ab42c81 P 54f46c4b90af49d0b13d5a48ace08c79: Deleting log segment in path: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515492304271-32569-0/minicluster-data/ts-0-root/wals/89e5fc3fb4cb44e89efbd7b95ab42c81/wal-000000009 (ops 41-44)
I20260812 06:18:14.036783   302 log.cc:1079] T 89e5fc3fb4cb44e89efbd7b95ab42c81 P 54f46c4b90af49d0b13d5a48ace08c79: Deleting log segment in path: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515492304271-32569-0/minicluster-data/ts-0-root/wals/89e5fc3fb4cb44e89efbd7b95ab42c81/wal-000000010 (ops 45-49)
I20260812 06:18:14.036815   302 log.cc:1079] T 89e5fc3fb4cb44e89efbd7b95ab42c81 P 54f46c4b90af49d0b13d5a48ace08c79: Deleting log segment in path: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515492304271-32569-0/minicluster-data/ts-0-root/wals/89e5fc3fb4cb44e89efbd7b95ab42c81/wal-000000011 (ops 50-54)
I20260812 06:18:14.036846   302 log.cc:1079] T 89e5fc3fb4cb44e89efbd7b95ab42c81 P 54f46c4b90af49d0b13d5a48ace08c79: Deleting log segment in path: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515492304271-32569-0/minicluster-data/ts-0-root/wals/89e5fc3fb4cb44e89efbd7b95ab42c81/wal-000000012 (ops 55-59)
I20260812 06:18:14.036877   302 log.cc:1079] T 89e5fc3fb4cb44e89efbd7b95ab42c81 P 54f46c4b90af49d0b13d5a48ace08c79: Deleting log segment in path: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515492304271-32569-0/minicluster-data/ts-0-root/wals/89e5fc3fb4cb44e89efbd7b95ab42c81/wal-000000013 (ops 60-64)
I20260812 06:18:14.036909   302 log.cc:1079] T 89e5fc3fb4cb44e89efbd7b95ab42c81 P 54f46c4b90af49d0b13d5a48ace08c79: Deleting log segment in path: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515492304271-32569-0/minicluster-data/ts-0-root/wals/89e5fc3fb4cb44e89efbd7b95ab42c81/wal-000000014 (ops 65-69)
I20260812 06:18:14.062929   302 maintenance_manager.cc:643] P 54f46c4b90af49d0b13d5a48ace08c79: LogGCOp(89e5fc3fb4cb44e89efbd7b95ab42c81) complete. Timing: real 0.026s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:18:14.063403   421 maintenance_manager.cc:419] P 54f46c4b90af49d0b13d5a48ace08c79: Scheduling FlushDeltaMemStoresOp(89e5fc3fb4cb44e89efbd7b95ab42c81): perf score=6.157687
I20260812 06:18:14.088706   302 maintenance_manager.cc:643] P 54f46c4b90af49d0b13d5a48ace08c79: FlushDeltaMemStoresOp(89e5fc3fb4cb44e89efbd7b95ab42c81) complete. Timing: real 0.025s	user 0.005s	sys 0.019s Metrics: {"bytes_written":7753813,"delete_count":0,"lbm_write_time_us":10231,"lbm_writes_lt_1ms":192,"reinsert_count":0,"update_count":945}
I20260812 06:18:14.089139   421 maintenance_manager.cc:419] P 54f46c4b90af49d0b13d5a48ace08c79: Scheduling UndoDeltaBlockGCOp(89e5fc3fb4cb44e89efbd7b95ab42c81): 462 bytes on disk
I20260812 06:18:14.089699   302 maintenance_manager.cc:643] P 54f46c4b90af49d0b13d5a48ace08c79: UndoDeltaBlockGCOp(89e5fc3fb4cb44e89efbd7b95ab42c81) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":57,"lbm_reads_lt_1ms":4}
I20260812 06:18:14.090278   421 maintenance_manager.cc:419] P 54f46c4b90af49d0b13d5a48ace08c79: Scheduling MajorDeltaCompactionOp(89e5fc3fb4cb44e89efbd7b95ab42c81): perf score=1.000000
I20260812 06:18:14.247392   302 maintenance_manager.cc:643] P 54f46c4b90af49d0b13d5a48ace08c79: MajorDeltaCompactionOp(89e5fc3fb4cb44e89efbd7b95ab42c81) complete. Timing: real 0.157s	user 0.123s	sys 0.031s Metrics: {"cfile_cache_miss":622,"cfile_cache_miss_bytes":28425958,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":247,"lbm_read_time_us":11911,"lbm_reads_lt_1ms":654,"lbm_write_time_us":30717,"lbm_writes_lt_1ms":632,"mutex_wait_us":63,"peak_mem_usage":74050703,"reinsert_count":0,"spinlock_wait_cycles":4480,"thread_start_us":70,"threads_started":1,"update_count":2945}
I20260812 06:18:14.247850   421 maintenance_manager.cc:419] P 54f46c4b90af49d0b13d5a48ace08c79: Scheduling FlushDeltaMemStoresOp(89e5fc3fb4cb44e89efbd7b95ab42c81): perf score=15.087375
I20260812 06:18:14.303531   302 maintenance_manager.cc:643] P 54f46c4b90af49d0b13d5a48ace08c79: FlushDeltaMemStoresOp(89e5fc3fb4cb44e89efbd7b95ab42c81) complete. Timing: real 0.056s	user 0.035s	sys 0.013s Metrics: {"bytes_written":16861171,"delete_count":0,"lbm_write_time_us":21734,"lbm_writes_lt_1ms":414,"reinsert_count":0,"update_count":2055}
I20260812 06:18:14.304008   421 maintenance_manager.cc:419] P 54f46c4b90af49d0b13d5a48ace08c79: Scheduling FlushDeltaMemStoresOp(89e5fc3fb4cb44e89efbd7b95ab42c81): perf score=2.188937
I20260812 06:18:14.319011   302 maintenance_manager.cc:643] P 54f46c4b90af49d0b13d5a48ace08c79: FlushDeltaMemStoresOp(89e5fc3fb4cb44e89efbd7b95ab42c81) complete. Timing: real 0.015s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5782,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:14.319501   421 maintenance_manager.cc:419] P 54f46c4b90af49d0b13d5a48ace08c79: Scheduling MajorDeltaCompactionOp(89e5fc3fb4cb44e89efbd7b95ab42c81): perf score=1.000000
I20260812 06:18:14.465925   302 maintenance_manager.cc:643] P 54f46c4b90af49d0b13d5a48ace08c79: MajorDeltaCompactionOp(89e5fc3fb4cb44e89efbd7b95ab42c81) complete. Timing: real 0.146s	user 0.113s	sys 0.020s Metrics: {"cfile_cache_miss":543,"cfile_cache_miss_bytes":25225958,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":240,"lbm_read_time_us":9892,"lbm_reads_lt_1ms":583,"lbm_write_time_us":27993,"lbm_writes_lt_1ms":554,"peak_mem_usage":63567285,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2555}
I20260812 06:18:14.466480   421 maintenance_manager.cc:419] P 54f46c4b90af49d0b13d5a48ace08c79: Scheduling FlushDeltaMemStoresOp(89e5fc3fb4cb44e89efbd7b95ab42c81): perf score=14.095187
I20260812 06:18:14.515424   302 maintenance_manager.cc:643] P 54f46c4b90af49d0b13d5a48ace08c79: FlushDeltaMemStoresOp(89e5fc3fb4cb44e89efbd7b95ab42c81) complete. Timing: real 0.049s	user 0.034s	sys 0.003s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":17123,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:14.515928   421 maintenance_manager.cc:419] P 54f46c4b90af49d0b13d5a48ace08c79: Scheduling FlushDeltaMemStoresOp(89e5fc3fb4cb44e89efbd7b95ab42c81): perf score=2.188937
I20260812 06:18:14.530296   302 maintenance_manager.cc:643] P 54f46c4b90af49d0b13d5a48ace08c79: FlushDeltaMemStoresOp(89e5fc3fb4cb44e89efbd7b95ab42c81) complete. Timing: real 0.014s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5491,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:14.530746   421 maintenance_manager.cc:419] P 54f46c4b90af49d0b13d5a48ace08c79: Scheduling MajorDeltaCompactionOp(89e5fc3fb4cb44e89efbd7b95ab42c81): perf score=1.000000
I20260812 06:18:14.686367   302 maintenance_manager.cc:643] P 54f46c4b90af49d0b13d5a48ace08c79: MajorDeltaCompactionOp(89e5fc3fb4cb44e89efbd7b95ab42c81) complete. Timing: real 0.155s	user 0.111s	sys 0.043s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":168,"lbm_read_time_us":12038,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25297,"lbm_writes_lt_1ms":543,"mutex_wait_us":20,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10240,"update_count":2500}
I20260812 06:18:14.686913   421 maintenance_manager.cc:419] P 54f46c4b90af49d0b13d5a48ace08c79: Scheduling FlushDeltaMemStoresOp(89e5fc3fb4cb44e89efbd7b95ab42c81): perf score=14.095187
I20260812 06:18:14.732041   302 maintenance_manager.cc:643] P 54f46c4b90af49d0b13d5a48ace08c79: FlushDeltaMemStoresOp(89e5fc3fb4cb44e89efbd7b95ab42c81) complete. Timing: real 0.044s	user 0.030s	sys 0.008s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":17946,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:14.732499   421 maintenance_manager.cc:419] P 54f46c4b90af49d0b13d5a48ace08c79: Scheduling MajorDeltaCompactionOp(89e5fc3fb4cb44e89efbd7b95ab42c81): perf score=1.000000
I20260812 06:18:14.880652   302 maintenance_manager.cc:643] P 54f46c4b90af49d0b13d5a48ace08c79: MajorDeltaCompactionOp(89e5fc3fb4cb44e89efbd7b95ab42c81) complete. Timing: real 0.148s	user 0.093s	sys 0.051s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672159,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":560,"lbm_read_time_us":10012,"lbm_reads_lt_1ms":463,"lbm_write_time_us":24535,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:14.881307   421 maintenance_manager.cc:419] P 54f46c4b90af49d0b13d5a48ace08c79: Scheduling FlushDeltaMemStoresOp(89e5fc3fb4cb44e89efbd7b95ab42c81): perf score=14.095187
I20260812 06:18:14.925601   302 maintenance_manager.cc:643] P 54f46c4b90af49d0b13d5a48ace08c79: FlushDeltaMemStoresOp(89e5fc3fb4cb44e89efbd7b95ab42c81) complete. Timing: real 0.044s	user 0.032s	sys 0.007s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18593,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:14.926201   421 maintenance_manager.cc:419] P 54f46c4b90af49d0b13d5a48ace08c79: Scheduling FlushDeltaMemStoresOp(89e5fc3fb4cb44e89efbd7b95ab42c81): perf score=2.188937
I20260812 06:18:14.936151   302 maintenance_manager.cc:643] P 54f46c4b90af49d0b13d5a48ace08c79: FlushDeltaMemStoresOp(89e5fc3fb4cb44e89efbd7b95ab42c81) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3870,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:14.936619   421 maintenance_manager.cc:419] P 54f46c4b90af49d0b13d5a48ace08c79: Scheduling MajorDeltaCompactionOp(89e5fc3fb4cb44e89efbd7b95ab42c81): perf score=1.000000
I20260812 06:18:15.111938   302 maintenance_manager.cc:643] P 54f46c4b90af49d0b13d5a48ace08c79: MajorDeltaCompactionOp(89e5fc3fb4cb44e89efbd7b95ab42c81) complete. Timing: real 0.175s	user 0.114s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":585,"lbm_read_time_us":10595,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29142,"lbm_writes_lt_1ms":543,"mutex_wait_us":48,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1536,"update_count":2500}
I20260812 06:18:15.112610   421 maintenance_manager.cc:419] P 54f46c4b90af49d0b13d5a48ace08c79: Scheduling FlushDeltaMemStoresOp(89e5fc3fb4cb44e89efbd7b95ab42c81): perf score=11.118625
I20260812 06:18:15.148489   302 maintenance_manager.cc:643] P 54f46c4b90af49d0b13d5a48ace08c79: FlushDeltaMemStoresOp(89e5fc3fb4cb44e89efbd7b95ab42c81) complete. Timing: real 0.036s	user 0.015s	sys 0.019s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":14591,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:15.149518   421 maintenance_manager.cc:419] P 54f46c4b90af49d0b13d5a48ace08c79: Scheduling FlushDeltaMemStoresOp(89e5fc3fb4cb44e89efbd7b95ab42c81): perf score=2.188937
I20260812 06:18:15.164700   302 maintenance_manager.cc:643] P 54f46c4b90af49d0b13d5a48ace08c79: FlushDeltaMemStoresOp(89e5fc3fb4cb44e89efbd7b95ab42c81) complete. Timing: real 0.015s	user 0.006s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4364,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:15.165104   421 maintenance_manager.cc:419] P 54f46c4b90af49d0b13d5a48ace08c79: Scheduling FlushDeltaMemStoresOp(89e5fc3fb4cb44e89efbd7b95ab42c81): perf score=2.188937
I20260812 06:18:15.174840   302 maintenance_manager.cc:643] P 54f46c4b90af49d0b13d5a48ace08c79: FlushDeltaMemStoresOp(89e5fc3fb4cb44e89efbd7b95ab42c81) complete. Timing: real 0.010s	user 0.004s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3755,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:15.175254   421 maintenance_manager.cc:419] P 54f46c4b90af49d0b13d5a48ace08c79: Scheduling MajorDeltaCompactionOp(89e5fc3fb4cb44e89efbd7b95ab42c81): perf score=1.000000
I20260812 06:18:15.332649   302 maintenance_manager.cc:643] P 54f46c4b90af49d0b13d5a48ace08c79: MajorDeltaCompactionOp(89e5fc3fb4cb44e89efbd7b95ab42c81) complete. Timing: real 0.157s	user 0.121s	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":782,"lbm_read_time_us":11267,"lbm_reads_lt_1ms":573,"lbm_write_time_us":32143,"lbm_writes_lt_1ms":543,"mutex_wait_us":259,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":2500}
I20260812 06:18:15.333210   421 maintenance_manager.cc:419] P 54f46c4b90af49d0b13d5a48ace08c79: Scheduling FlushDeltaMemStoresOp(89e5fc3fb4cb44e89efbd7b95ab42c81): perf score=11.118625
I20260812 06:18:15.373392   302 maintenance_manager.cc:643] P 54f46c4b90af49d0b13d5a48ace08c79: FlushDeltaMemStoresOp(89e5fc3fb4cb44e89efbd7b95ab42c81) complete. Timing: real 0.040s	user 0.016s	sys 0.019s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":16177,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:15.373850   421 maintenance_manager.cc:419] P 54f46c4b90af49d0b13d5a48ace08c79: Scheduling FlushDeltaMemStoresOp(89e5fc3fb4cb44e89efbd7b95ab42c81): perf score=2.188937
I20260812 06:18:15.384488   302 maintenance_manager.cc:643] P 54f46c4b90af49d0b13d5a48ace08c79: FlushDeltaMemStoresOp(89e5fc3fb4cb44e89efbd7b95ab42c81) complete. Timing: real 0.010s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4194,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:15.384873   421 maintenance_manager.cc:419] P 54f46c4b90af49d0b13d5a48ace08c79: Scheduling FlushDeltaMemStoresOp(89e5fc3fb4cb44e89efbd7b95ab42c81): perf score=2.188937
I20260812 06:18:15.393579   302 maintenance_manager.cc:643] P 54f46c4b90af49d0b13d5a48ace08c79: FlushDeltaMemStoresOp(89e5fc3fb4cb44e89efbd7b95ab42c81) complete. Timing: real 0.009s	user 0.003s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3302,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:15.393960   421 maintenance_manager.cc:419] P 54f46c4b90af49d0b13d5a48ace08c79: Scheduling FlushMRSOp(89e5fc3fb4cb44e89efbd7b95ab42c81): perf score=1.000000
I20260812 06:18:15.426899   302 maintenance_manager.cc:643] P 54f46c4b90af49d0b13d5a48ace08c79: FlushMRSOp(89e5fc3fb4cb44e89efbd7b95ab42c81) complete. Timing: real 0.033s	user 0.027s	sys 0.005s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":57,"dirs.run_cpu_time_us":214,"dirs.run_wall_time_us":1023,"drs_written":1,"lbm_read_time_us":42,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1533,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:18:15.427631   421 maintenance_manager.cc:419] P 54f46c4b90af49d0b13d5a48ace08c79: Scheduling LogGCOp(89e5fc3fb4cb44e89efbd7b95ab42c81): free 124257256 bytes of WAL
I20260812 06:18:15.427843   302 log_reader.cc:385] T 89e5fc3fb4cb44e89efbd7b95ab42c81: removed 12 log segments from log reader
I20260812 06:18:15.427891   302 log.cc:1079] T 89e5fc3fb4cb44e89efbd7b95ab42c81 P 54f46c4b90af49d0b13d5a48ace08c79: Deleting log segment in path: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515492304271-32569-0/minicluster-data/ts-0-root/wals/89e5fc3fb4cb44e89efbd7b95ab42c81/wal-000000015 (ops 70-74)
I20260812 06:18:15.427918   302 log.cc:1079] T 89e5fc3fb4cb44e89efbd7b95ab42c81 P 54f46c4b90af49d0b13d5a48ace08c79: Deleting log segment in path: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515492304271-32569-0/minicluster-data/ts-0-root/wals/89e5fc3fb4cb44e89efbd7b95ab42c81/wal-000000016 (ops 75-79)
I20260812 06:18:15.427951   302 log.cc:1079] T 89e5fc3fb4cb44e89efbd7b95ab42c81 P 54f46c4b90af49d0b13d5a48ace08c79: Deleting log segment in path: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515492304271-32569-0/minicluster-data/ts-0-root/wals/89e5fc3fb4cb44e89efbd7b95ab42c81/wal-000000017 (ops 80-84)
I20260812 06:18:15.427976   302 log.cc:1079] T 89e5fc3fb4cb44e89efbd7b95ab42c81 P 54f46c4b90af49d0b13d5a48ace08c79: Deleting log segment in path: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515492304271-32569-0/minicluster-data/ts-0-root/wals/89e5fc3fb4cb44e89efbd7b95ab42c81/wal-000000018 (ops 85-88)
I20260812 06:18:15.428007   302 log.cc:1079] T 89e5fc3fb4cb44e89efbd7b95ab42c81 P 54f46c4b90af49d0b13d5a48ace08c79: Deleting log segment in path: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515492304271-32569-0/minicluster-data/ts-0-root/wals/89e5fc3fb4cb44e89efbd7b95ab42c81/wal-000000019 (ops 89-93)
I20260812 06:18:15.428038   302 log.cc:1079] T 89e5fc3fb4cb44e89efbd7b95ab42c81 P 54f46c4b90af49d0b13d5a48ace08c79: Deleting log segment in path: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515492304271-32569-0/minicluster-data/ts-0-root/wals/89e5fc3fb4cb44e89efbd7b95ab42c81/wal-000000020 (ops 94-98)
I20260812 06:18:15.428071   302 log.cc:1079] T 89e5fc3fb4cb44e89efbd7b95ab42c81 P 54f46c4b90af49d0b13d5a48ace08c79: Deleting log segment in path: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515492304271-32569-0/minicluster-data/ts-0-root/wals/89e5fc3fb4cb44e89efbd7b95ab42c81/wal-000000021 (ops 99-103)
I20260812 06:18:15.428103   302 log.cc:1079] T 89e5fc3fb4cb44e89efbd7b95ab42c81 P 54f46c4b90af49d0b13d5a48ace08c79: Deleting log segment in path: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515492304271-32569-0/minicluster-data/ts-0-root/wals/89e5fc3fb4cb44e89efbd7b95ab42c81/wal-000000022 (ops 104-108)
I20260812 06:18:15.428136   302 log.cc:1079] T 89e5fc3fb4cb44e89efbd7b95ab42c81 P 54f46c4b90af49d0b13d5a48ace08c79: Deleting log segment in path: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515492304271-32569-0/minicluster-data/ts-0-root/wals/89e5fc3fb4cb44e89efbd7b95ab42c81/wal-000000023 (ops 109-113)
I20260812 06:18:15.428167   302 log.cc:1079] T 89e5fc3fb4cb44e89efbd7b95ab42c81 P 54f46c4b90af49d0b13d5a48ace08c79: Deleting log segment in path: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515492304271-32569-0/minicluster-data/ts-0-root/wals/89e5fc3fb4cb44e89efbd7b95ab42c81/wal-000000024 (ops 114-118)
I20260812 06:18:15.428200   302 log.cc:1079] T 89e5fc3fb4cb44e89efbd7b95ab42c81 P 54f46c4b90af49d0b13d5a48ace08c79: Deleting log segment in path: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515492304271-32569-0/minicluster-data/ts-0-root/wals/89e5fc3fb4cb44e89efbd7b95ab42c81/wal-000000025 (ops 119-123)
I20260812 06:18:15.428231   302 log.cc:1079] T 89e5fc3fb4cb44e89efbd7b95ab42c81 P 54f46c4b90af49d0b13d5a48ace08c79: Deleting log segment in path: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515492304271-32569-0/minicluster-data/ts-0-root/wals/89e5fc3fb4cb44e89efbd7b95ab42c81/wal-000000026 (ops 124-128)
I20260812 06:18:15.451660   302 maintenance_manager.cc:643] P 54f46c4b90af49d0b13d5a48ace08c79: LogGCOp(89e5fc3fb4cb44e89efbd7b95ab42c81) complete. Timing: real 0.024s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:18:15.452065   421 maintenance_manager.cc:419] P 54f46c4b90af49d0b13d5a48ace08c79: Scheduling UndoDeltaBlockGCOp(89e5fc3fb4cb44e89efbd7b95ab42c81): 482 bytes on disk
I20260812 06:18:15.452544   302 maintenance_manager.cc:643] P 54f46c4b90af49d0b13d5a48ace08c79: UndoDeltaBlockGCOp(89e5fc3fb4cb44e89efbd7b95ab42c81) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":71,"lbm_reads_lt_1ms":4}
I20260812 06:18:15.453066   421 maintenance_manager.cc:419] P 54f46c4b90af49d0b13d5a48ace08c79: Scheduling FlushDeltaMemStoresOp(89e5fc3fb4cb44e89efbd7b95ab42c81): perf score=4.173312
I20260812 06:18:15.478785   302 maintenance_manager.cc:643] P 54f46c4b90af49d0b13d5a48ace08c79: FlushDeltaMemStoresOp(89e5fc3fb4cb44e89efbd7b95ab42c81) complete. Timing: real 0.026s	user 0.018s	sys 0.007s Metrics: {"bytes_written":5374417,"delete_count":0,"lbm_write_time_us":7081,"lbm_writes_lt_1ms":134,"reinsert_count":0,"update_count":655}
I20260812 06:18:15.479184   421 maintenance_manager.cc:419] P 54f46c4b90af49d0b13d5a48ace08c79: Scheduling FlushDeltaMemStoresOp(89e5fc3fb4cb44e89efbd7b95ab42c81): perf score=1.196750
I20260812 06:18:15.486371   302 maintenance_manager.cc:643] P 54f46c4b90af49d0b13d5a48ace08c79: FlushDeltaMemStoresOp(89e5fc3fb4cb44e89efbd7b95ab42c81) complete. Timing: real 0.007s	user 0.002s	sys 0.005s Metrics: {"bytes_written":2830880,"delete_count":0,"lbm_write_time_us":2587,"lbm_writes_lt_1ms":72,"reinsert_count":0,"update_count":345}
I20260812 06:18:15.486699   421 maintenance_manager.cc:419] P 54f46c4b90af49d0b13d5a48ace08c79: Scheduling MajorDeltaCompactionOp(89e5fc3fb4cb44e89efbd7b95ab42c81): perf score=1.000000
I20260812 06:18:15.698457   302 maintenance_manager.cc:643] P 54f46c4b90af49d0b13d5a48ace08c79: MajorDeltaCompactionOp(89e5fc3fb4cb44e89efbd7b95ab42c81) complete. Timing: real 0.212s	user 0.151s	sys 0.060s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32979834,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":361,"lbm_read_time_us":15318,"lbm_reads_lt_1ms":775,"lbm_write_time_us":37790,"lbm_writes_lt_1ms":743,"mutex_wait_us":29,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":16000,"thread_start_us":70,"threads_started":1,"update_count":3500}
I20260812 06:18:15.700611   421 maintenance_manager.cc:419] P 54f46c4b90af49d0b13d5a48ace08c79: Scheduling FlushDeltaMemStoresOp(89e5fc3fb4cb44e89efbd7b95ab42c81): perf score=14.095187
I20260812 06:18:15.759404   302 maintenance_manager.cc:643] P 54f46c4b90af49d0b13d5a48ace08c79: FlushDeltaMemStoresOp(89e5fc3fb4cb44e89efbd7b95ab42c81) complete. Timing: real 0.059s	user 0.037s	sys 0.020s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":27977,"lbm_writes_1-10_ms":4,"lbm_writes_lt_1ms":399,"reinsert_count":0,"update_count":2000}
I20260812 06:18:15.760491   421 maintenance_manager.cc:419] P 54f46c4b90af49d0b13d5a48ace08c79: Scheduling FlushDeltaMemStoresOp(89e5fc3fb4cb44e89efbd7b95ab42c81): perf score=2.188937
I20260812 06:18:15.777000   302 maintenance_manager.cc:643] P 54f46c4b90af49d0b13d5a48ace08c79: FlushDeltaMemStoresOp(89e5fc3fb4cb44e89efbd7b95ab42c81) complete. Timing: real 0.015s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4637,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:15.777446   421 maintenance_manager.cc:419] P 54f46c4b90af49d0b13d5a48ace08c79: Scheduling MajorDeltaCompactionOp(89e5fc3fb4cb44e89efbd7b95ab42c81): perf score=1.000000
I20260812 06:18:15.953600   302 maintenance_manager.cc:643] P 54f46c4b90af49d0b13d5a48ace08c79: MajorDeltaCompactionOp(89e5fc3fb4cb44e89efbd7b95ab42c81) complete. Timing: real 0.176s	user 0.120s	sys 0.044s 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":193,"lbm_read_time_us":10899,"lbm_reads_lt_1ms":564,"lbm_write_time_us":27898,"lbm_writes_lt_1ms":543,"mutex_wait_us":25,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11904,"update_count":2500}
I20260812 06:18:15.954074   421 maintenance_manager.cc:419] P 54f46c4b90af49d0b13d5a48ace08c79: Scheduling FlushDeltaMemStoresOp(89e5fc3fb4cb44e89efbd7b95ab42c81): perf score=18.063937
I20260812 06:18:16.013736   302 maintenance_manager.cc:643] P 54f46c4b90af49d0b13d5a48ace08c79: FlushDeltaMemStoresOp(89e5fc3fb4cb44e89efbd7b95ab42c81) complete. Timing: real 0.060s	user 0.044s	sys 0.012s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":27057,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:16.014303   421 maintenance_manager.cc:419] P 54f46c4b90af49d0b13d5a48ace08c79: Scheduling FlushDeltaMemStoresOp(89e5fc3fb4cb44e89efbd7b95ab42c81): perf score=2.188937
I20260812 06:18:16.024664   302 maintenance_manager.cc:643] P 54f46c4b90af49d0b13d5a48ace08c79: FlushDeltaMemStoresOp(89e5fc3fb4cb44e89efbd7b95ab42c81) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3961,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:16.025281   421 maintenance_manager.cc:419] P 54f46c4b90af49d0b13d5a48ace08c79: Scheduling MajorDeltaCompactionOp(89e5fc3fb4cb44e89efbd7b95ab42c81): perf score=1.000000
I20260812 06:18:16.214820   302 maintenance_manager.cc:643] P 54f46c4b90af49d0b13d5a48ace08c79: MajorDeltaCompactionOp(89e5fc3fb4cb44e89efbd7b95ab42c81) complete. Timing: real 0.189s	user 0.133s	sys 0.055s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877102,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1731,"lbm_read_time_us":14169,"lbm_reads_lt_1ms":672,"lbm_write_time_us":31795,"lbm_writes_lt_1ms":643,"mutex_wait_us":523,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":10496,"update_count":3000}
I20260812 06:18:16.215386   421 maintenance_manager.cc:419] P 54f46c4b90af49d0b13d5a48ace08c79: Scheduling FlushDeltaMemStoresOp(89e5fc3fb4cb44e89efbd7b95ab42c81): perf score=14.095187
I20260812 06:18:16.271756   302 maintenance_manager.cc:643] P 54f46c4b90af49d0b13d5a48ace08c79: FlushDeltaMemStoresOp(89e5fc3fb4cb44e89efbd7b95ab42c81) complete. Timing: real 0.056s	user 0.032s	sys 0.013s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20630,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:16.272239   421 maintenance_manager.cc:419] P 54f46c4b90af49d0b13d5a48ace08c79: Scheduling FlushDeltaMemStoresOp(89e5fc3fb4cb44e89efbd7b95ab42c81): perf score=2.188937
I20260812 06:18:16.284547   302 maintenance_manager.cc:643] P 54f46c4b90af49d0b13d5a48ace08c79: FlushDeltaMemStoresOp(89e5fc3fb4cb44e89efbd7b95ab42c81) complete. Timing: real 0.012s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4984,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:16.285050   421 maintenance_manager.cc:419] P 54f46c4b90af49d0b13d5a48ace08c79: Scheduling MajorDeltaCompactionOp(89e5fc3fb4cb44e89efbd7b95ab42c81): perf score=1.000000
I20260812 06:18:16.456040   302 maintenance_manager.cc:643] P 54f46c4b90af49d0b13d5a48ace08c79: MajorDeltaCompactionOp(89e5fc3fb4cb44e89efbd7b95ab42c81) complete. Timing: real 0.171s	user 0.109s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":254,"lbm_read_time_us":12630,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28104,"lbm_writes_lt_1ms":543,"mutex_wait_us":42,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8064,"update_count":2500}
I20260812 06:18:16.456821   421 maintenance_manager.cc:419] P 54f46c4b90af49d0b13d5a48ace08c79: Scheduling FlushDeltaMemStoresOp(89e5fc3fb4cb44e89efbd7b95ab42c81): perf score=14.095187
I20260812 06:18:16.520123   302 maintenance_manager.cc:643] P 54f46c4b90af49d0b13d5a48ace08c79: FlushDeltaMemStoresOp(89e5fc3fb4cb44e89efbd7b95ab42c81) complete. Timing: real 0.063s	user 0.033s	sys 0.014s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":21378,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:16.520608   421 maintenance_manager.cc:419] P 54f46c4b90af49d0b13d5a48ace08c79: Scheduling FlushDeltaMemStoresOp(89e5fc3fb4cb44e89efbd7b95ab42c81): perf score=2.188937
I20260812 06:18:16.530381   302 maintenance_manager.cc:643] P 54f46c4b90af49d0b13d5a48ace08c79: FlushDeltaMemStoresOp(89e5fc3fb4cb44e89efbd7b95ab42c81) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3833,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:16.530782   421 maintenance_manager.cc:419] P 54f46c4b90af49d0b13d5a48ace08c79: Scheduling MajorDeltaCompactionOp(89e5fc3fb4cb44e89efbd7b95ab42c81): perf score=1.000000
I20260812 06:18:16.701481   302 maintenance_manager.cc:643] P 54f46c4b90af49d0b13d5a48ace08c79: MajorDeltaCompactionOp(89e5fc3fb4cb44e89efbd7b95ab42c81) complete. Timing: real 0.171s	user 0.122s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774691,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":181,"lbm_read_time_us":12846,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29438,"lbm_writes_lt_1ms":543,"mutex_wait_us":50,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4480,"update_count":2500}
I20260812 06:18:16.702304   421 maintenance_manager.cc:419] P 54f46c4b90af49d0b13d5a48ace08c79: Scheduling FlushDeltaMemStoresOp(89e5fc3fb4cb44e89efbd7b95ab42c81): perf score=14.095187
I20260812 06:18:16.760743   302 maintenance_manager.cc:643] P 54f46c4b90af49d0b13d5a48ace08c79: FlushDeltaMemStoresOp(89e5fc3fb4cb44e89efbd7b95ab42c81) complete. Timing: real 0.058s	user 0.028s	sys 0.024s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20012,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:16.761243   421 maintenance_manager.cc:419] P 54f46c4b90af49d0b13d5a48ace08c79: Scheduling FlushDeltaMemStoresOp(89e5fc3fb4cb44e89efbd7b95ab42c81): perf score=2.188937
I20260812 06:18:16.776041   302 maintenance_manager.cc:643] P 54f46c4b90af49d0b13d5a48ace08c79: FlushDeltaMemStoresOp(89e5fc3fb4cb44e89efbd7b95ab42c81) complete. Timing: real 0.015s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5611,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:16.776551   421 maintenance_manager.cc:419] P 54f46c4b90af49d0b13d5a48ace08c79: Scheduling FlushMRSOp(89e5fc3fb4cb44e89efbd7b95ab42c81): perf score=1.000000
I20260812 06:18:16.805186   302 maintenance_manager.cc:643] P 54f46c4b90af49d0b13d5a48ace08c79: FlushMRSOp(89e5fc3fb4cb44e89efbd7b95ab42c81) complete. Timing: real 0.028s	user 0.027s	sys 0.000s Metrics: {"bytes_written":1152510,"cfile_init":1,"dirs.queue_time_us":62,"dirs.run_cpu_time_us":186,"dirs.run_wall_time_us":1197,"drs_written":1,"lbm_read_time_us":41,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1431,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:16.805989   421 maintenance_manager.cc:419] P 54f46c4b90af49d0b13d5a48ace08c79: Scheduling MajorDeltaCompactionOp(89e5fc3fb4cb44e89efbd7b95ab42c81): perf score=1.000000
I20260812 06:18:16.971791   302 maintenance_manager.cc:643] P 54f46c4b90af49d0b13d5a48ace08c79: MajorDeltaCompactionOp(89e5fc3fb4cb44e89efbd7b95ab42c81) complete. Timing: real 0.166s	user 0.125s	sys 0.041s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":134,"lbm_read_time_us":11016,"lbm_reads_lt_1ms":564,"lbm_write_time_us":31193,"lbm_writes_lt_1ms":543,"mutex_wait_us":28,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2432,"update_count":2500}
I20260812 06:18:16.972429   421 maintenance_manager.cc:419] P 54f46c4b90af49d0b13d5a48ace08c79: Scheduling LogGCOp(89e5fc3fb4cb44e89efbd7b95ab42c81): free 121006648 bytes of WAL
I20260812 06:18:16.972810   302 log_reader.cc:385] T 89e5fc3fb4cb44e89efbd7b95ab42c81: removed 12 log segments from log reader
I20260812 06:18:16.972870   302 log.cc:1079] T 89e5fc3fb4cb44e89efbd7b95ab42c81 P 54f46c4b90af49d0b13d5a48ace08c79: Deleting log segment in path: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515492304271-32569-0/minicluster-data/ts-0-root/wals/89e5fc3fb4cb44e89efbd7b95ab42c81/wal-000000027 (ops 129-133)
I20260812 06:18:16.972908   302 log.cc:1079] T 89e5fc3fb4cb44e89efbd7b95ab42c81 P 54f46c4b90af49d0b13d5a48ace08c79: Deleting log segment in path: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515492304271-32569-0/minicluster-data/ts-0-root/wals/89e5fc3fb4cb44e89efbd7b95ab42c81/wal-000000028 (ops 134-138)
I20260812 06:18:16.972929   302 log.cc:1079] T 89e5fc3fb4cb44e89efbd7b95ab42c81 P 54f46c4b90af49d0b13d5a48ace08c79: Deleting log segment in path: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515492304271-32569-0/minicluster-data/ts-0-root/wals/89e5fc3fb4cb44e89efbd7b95ab42c81/wal-000000029 (ops 139-143)
I20260812 06:18:16.972985   302 log.cc:1079] T 89e5fc3fb4cb44e89efbd7b95ab42c81 P 54f46c4b90af49d0b13d5a48ace08c79: Deleting log segment in path: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515492304271-32569-0/minicluster-data/ts-0-root/wals/89e5fc3fb4cb44e89efbd7b95ab42c81/wal-000000030 (ops 144-148)
I20260812 06:18:16.973016   302 log.cc:1079] T 89e5fc3fb4cb44e89efbd7b95ab42c81 P 54f46c4b90af49d0b13d5a48ace08c79: Deleting log segment in path: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515492304271-32569-0/minicluster-data/ts-0-root/wals/89e5fc3fb4cb44e89efbd7b95ab42c81/wal-000000031 (ops 149-153)
I20260812 06:18:16.973037   302 log.cc:1079] T 89e5fc3fb4cb44e89efbd7b95ab42c81 P 54f46c4b90af49d0b13d5a48ace08c79: Deleting log segment in path: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515492304271-32569-0/minicluster-data/ts-0-root/wals/89e5fc3fb4cb44e89efbd7b95ab42c81/wal-000000032 (ops 154-158)
I20260812 06:18:16.973066   302 log.cc:1079] T 89e5fc3fb4cb44e89efbd7b95ab42c81 P 54f46c4b90af49d0b13d5a48ace08c79: Deleting log segment in path: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515492304271-32569-0/minicluster-data/ts-0-root/wals/89e5fc3fb4cb44e89efbd7b95ab42c81/wal-000000033 (ops 159-163)
I20260812 06:18:16.973121   302 log.cc:1079] T 89e5fc3fb4cb44e89efbd7b95ab42c81 P 54f46c4b90af49d0b13d5a48ace08c79: Deleting log segment in path: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515492304271-32569-0/minicluster-data/ts-0-root/wals/89e5fc3fb4cb44e89efbd7b95ab42c81/wal-000000034 (ops 164-168)
I20260812 06:18:16.973153   302 log.cc:1079] T 89e5fc3fb4cb44e89efbd7b95ab42c81 P 54f46c4b90af49d0b13d5a48ace08c79: Deleting log segment in path: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515492304271-32569-0/minicluster-data/ts-0-root/wals/89e5fc3fb4cb44e89efbd7b95ab42c81/wal-000000035 (ops 169-173)
I20260812 06:18:16.973176   302 log.cc:1079] T 89e5fc3fb4cb44e89efbd7b95ab42c81 P 54f46c4b90af49d0b13d5a48ace08c79: Deleting log segment in path: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515492304271-32569-0/minicluster-data/ts-0-root/wals/89e5fc3fb4cb44e89efbd7b95ab42c81/wal-000000036 (ops 174-178)
I20260812 06:18:16.973196   302 log.cc:1079] T 89e5fc3fb4cb44e89efbd7b95ab42c81 P 54f46c4b90af49d0b13d5a48ace08c79: Deleting log segment in path: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515492304271-32569-0/minicluster-data/ts-0-root/wals/89e5fc3fb4cb44e89efbd7b95ab42c81/wal-000000037 (ops 179-182)
I20260812 06:18:16.973233   302 log.cc:1079] T 89e5fc3fb4cb44e89efbd7b95ab42c81 P 54f46c4b90af49d0b13d5a48ace08c79: Deleting log segment in path: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515492304271-32569-0/minicluster-data/ts-0-root/wals/89e5fc3fb4cb44e89efbd7b95ab42c81/wal-000000038 (ops 183-187)
I20260812 06:18:16.998097   302 maintenance_manager.cc:643] P 54f46c4b90af49d0b13d5a48ace08c79: LogGCOp(89e5fc3fb4cb44e89efbd7b95ab42c81) complete. Timing: real 0.025s	user 0.003s	sys 0.023s Metrics: {}
I20260812 06:18:16.998494   421 maintenance_manager.cc:419] P 54f46c4b90af49d0b13d5a48ace08c79: Scheduling UndoDeltaBlockGCOp(89e5fc3fb4cb44e89efbd7b95ab42c81): 448 bytes on disk
I20260812 06:18:16.998924   302 maintenance_manager.cc:643] P 54f46c4b90af49d0b13d5a48ace08c79: UndoDeltaBlockGCOp(89e5fc3fb4cb44e89efbd7b95ab42c81) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4}
I20260812 06:18:16.999495   421 maintenance_manager.cc:419] P 54f46c4b90af49d0b13d5a48ace08c79: Scheduling FlushDeltaMemStoresOp(89e5fc3fb4cb44e89efbd7b95ab42c81): perf score=18.063937
I20260812 06:18:17.051654   302 maintenance_manager.cc:643] P 54f46c4b90af49d0b13d5a48ace08c79: FlushDeltaMemStoresOp(89e5fc3fb4cb44e89efbd7b95ab42c81) complete. Timing: real 0.052s	user 0.031s	sys 0.019s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":20140,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:17.052150   421 maintenance_manager.cc:419] P 54f46c4b90af49d0b13d5a48ace08c79: Scheduling FlushDeltaMemStoresOp(89e5fc3fb4cb44e89efbd7b95ab42c81): perf score=2.188937
I20260812 06:18:17.062193   302 maintenance_manager.cc:643] P 54f46c4b90af49d0b13d5a48ace08c79: FlushDeltaMemStoresOp(89e5fc3fb4cb44e89efbd7b95ab42c81) complete. Timing: real 0.010s	user 0.004s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3921,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:17.062636   421 maintenance_manager.cc:419] P 54f46c4b90af49d0b13d5a48ace08c79: Scheduling MajorDeltaCompactionOp(89e5fc3fb4cb44e89efbd7b95ab42c81): perf score=1.000000
I20260812 06:18:17.154323 32569 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.600s	user 1.699s	sys 0.194s
I20260812 06:18:17.233649 32569 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.079s	user 0.000s	sys 0.001s
I20260812 06:18:17.234299 32569 tablet_server.cc:179] TabletServer@127.31.206.65:0 shutting down...
I20260812 06:18:17.243932   302 maintenance_manager.cc:643] P 54f46c4b90af49d0b13d5a48ace08c79: MajorDeltaCompactionOp(89e5fc3fb4cb44e89efbd7b95ab42c81) complete. Timing: real 0.181s	user 0.110s	sys 0.070s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877103,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":180,"lbm_read_time_us":14949,"lbm_reads_lt_1ms":668,"lbm_write_time_us":30133,"lbm_writes_lt_1ms":643,"mutex_wait_us":48,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":6272,"update_count":3000}
I20260812 06:18:17.244799 32569 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:17.245141 32569 tablet_replica.cc:333] T 89e5fc3fb4cb44e89efbd7b95ab42c81 P 54f46c4b90af49d0b13d5a48ace08c79: stopping tablet replica
I20260812 06:18:17.245350 32569 raft_consensus.cc:2243] T 89e5fc3fb4cb44e89efbd7b95ab42c81 P 54f46c4b90af49d0b13d5a48ace08c79 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:17.245563 32569 raft_consensus.cc:2272] T 89e5fc3fb4cb44e89efbd7b95ab42c81 P 54f46c4b90af49d0b13d5a48ace08c79 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:17.251866 32569 tablet_server.cc:196] TabletServer@127.31.206.65:0 shutdown complete.
I20260812 06:18:17.297534 32569 master.cc:562] Master@127.31.206.126:33829 shutting down...
I20260812 06:18:17.300698 32569 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 6470be5713f34aa6b71006b72162cbe0 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:17.300863 32569 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 6470be5713f34aa6b71006b72162cbe0 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:17.300915 32569 tablet_replica.cc:333] T 00000000000000000000000000000000 P 6470be5713f34aa6b71006b72162cbe0: stopping tablet replica
I20260812 06:18:17.313014 32569 master.cc:584] Master@127.31.206.126:33829 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5073 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:18:17.399224 32569 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.31.206.126:40225
I20260812 06:18:17.399569 32569 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:17.401309   485 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:17.401425   488 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:17.401556   493 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:17.401594 32569 server_base.cc:1061] running on GCE node
I20260812 06:18:17.401787 32569 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:17.401825 32569 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:17.401844 32569 hybrid_clock.cc:648] HybridClock initialized: now 1786515497401844 us; error 0 us; skew 500 ppm
I20260812 06:18:17.403234 32569 webserver.cc:533] Webserver started at http://127.31.206.126:40013/ using document root <none> and password file <none>
I20260812 06:18:17.403388 32569 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:17.403429 32569 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:17.403503 32569 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:17.403863 32569 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515492304271-32569-0/minicluster-data/master-0-root/instance:
uuid: "28f2906f328f40818af3f2818653815e"
format_stamp: "Formatted at 2026-08-12 06:18:17 on dist-test-slave-q9h9"
I20260812 06:18:17.405241 32569 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:18:17.406096   505 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:17.406328 32569 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:18:17.406392 32569 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515492304271-32569-0/minicluster-data/master-0-root
uuid: "28f2906f328f40818af3f2818653815e"
format_stamp: "Formatted at 2026-08-12 06:18:17 on dist-test-slave-q9h9"
I20260812 06:18:17.406446 32569 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515492304271-32569-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515492304271-32569-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515492304271-32569-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:17.412834 32569 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:17.413087 32569 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:17.416762 32569 rpc_server.cc:307] RPC server started. Bound to: 127.31.206.126:40225
I20260812 06:18:17.421830   604 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.31.206.126:40225 every 8 connection(s)
I20260812 06:18:17.422262   605 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:17.423966   605 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 28f2906f328f40818af3f2818653815e: Bootstrap starting.
I20260812 06:18:17.424651   605 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 28f2906f328f40818af3f2818653815e: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:17.425482   605 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 28f2906f328f40818af3f2818653815e: No bootstrap required, opened a new log
I20260812 06:18:17.425829   605 raft_consensus.cc:359] T 00000000000000000000000000000000 P 28f2906f328f40818af3f2818653815e [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "28f2906f328f40818af3f2818653815e" member_type: VOTER }
I20260812 06:18:17.425904   605 raft_consensus.cc:385] T 00000000000000000000000000000000 P 28f2906f328f40818af3f2818653815e [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:17.425932   605 raft_consensus.cc:740] T 00000000000000000000000000000000 P 28f2906f328f40818af3f2818653815e [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 28f2906f328f40818af3f2818653815e, State: Initialized, Role: FOLLOWER
I20260812 06:18:17.426065   605 consensus_queue.cc:260] T 00000000000000000000000000000000 P 28f2906f328f40818af3f2818653815e [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: "28f2906f328f40818af3f2818653815e" member_type: VOTER }
I20260812 06:18:17.426158   605 raft_consensus.cc:399] T 00000000000000000000000000000000 P 28f2906f328f40818af3f2818653815e [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:17.426188   605 raft_consensus.cc:493] T 00000000000000000000000000000000 P 28f2906f328f40818af3f2818653815e [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:17.426223   605 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 28f2906f328f40818af3f2818653815e [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:17.426805   605 raft_consensus.cc:515] T 00000000000000000000000000000000 P 28f2906f328f40818af3f2818653815e [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "28f2906f328f40818af3f2818653815e" member_type: VOTER }
I20260812 06:18:17.426919   605 leader_election.cc:304] T 00000000000000000000000000000000 P 28f2906f328f40818af3f2818653815e [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: 28f2906f328f40818af3f2818653815e; no voters: 
I20260812 06:18:17.427062   605 leader_election.cc:290] T 00000000000000000000000000000000 P 28f2906f328f40818af3f2818653815e [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:17.427173   608 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 28f2906f328f40818af3f2818653815e [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:17.427341   608 raft_consensus.cc:697] T 00000000000000000000000000000000 P 28f2906f328f40818af3f2818653815e [term 1 LEADER]: Becoming Leader. State: Replica: 28f2906f328f40818af3f2818653815e, State: Running, Role: LEADER
I20260812 06:18:17.427482   605 sys_catalog.cc:565] T 00000000000000000000000000000000 P 28f2906f328f40818af3f2818653815e [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:17.427471   608 consensus_queue.cc:237] T 00000000000000000000000000000000 P 28f2906f328f40818af3f2818653815e [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: "28f2906f328f40818af3f2818653815e" member_type: VOTER }
I20260812 06:18:17.427877   613 sys_catalog.cc:455] T 00000000000000000000000000000000 P 28f2906f328f40818af3f2818653815e [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "28f2906f328f40818af3f2818653815e" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "28f2906f328f40818af3f2818653815e" member_type: VOTER } }
I20260812 06:18:17.427980   613 sys_catalog.cc:458] T 00000000000000000000000000000000 P 28f2906f328f40818af3f2818653815e [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:17.427893   614 sys_catalog.cc:455] T 00000000000000000000000000000000 P 28f2906f328f40818af3f2818653815e [sys.catalog]: SysCatalogTable state changed. Reason: New leader 28f2906f328f40818af3f2818653815e. Latest consensus state: current_term: 1 leader_uuid: "28f2906f328f40818af3f2818653815e" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "28f2906f328f40818af3f2818653815e" member_type: VOTER } }
I20260812 06:18:17.428102   614 sys_catalog.cc:458] T 00000000000000000000000000000000 P 28f2906f328f40818af3f2818653815e [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:17.428619   618 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:17.429272   618 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:17.429471 32569 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:17.431025   618 catalog_manager.cc:1383] Generated new cluster ID: f350c5791cc64a30a2782fc7a810546c
I20260812 06:18:17.431080   618 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:17.446321   618 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:17.446772   618 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:17.462047   618 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 28f2906f328f40818af3f2818653815e: Generated new TSK 0
I20260812 06:18:17.462182   618 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:17.493777 32569 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:17.495685   643 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:17.495806   649 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:17.495843   644 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:17.495978 32569 server_base.cc:1061] running on GCE node
I20260812 06:18:17.496127 32569 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:17.496165 32569 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:17.496177 32569 hybrid_clock.cc:648] HybridClock initialized: now 1786515497496178 us; error 0 us; skew 500 ppm
I20260812 06:18:17.496932 32569 webserver.cc:533] Webserver started at http://127.31.206.65:35079/ using document root <none> and password file <none>
I20260812 06:18:17.497085 32569 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:17.497134 32569 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:17.497211 32569 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:17.497589 32569 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515492304271-32569-0/minicluster-data/ts-0-root/instance:
uuid: "c39cbdd68e1f4e5a9f319d842c688300"
format_stamp: "Formatted at 2026-08-12 06:18:17 on dist-test-slave-q9h9"
I20260812 06:18:17.499038 32569 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:18:17.499902   656 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:17.500139 32569 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:18:17.500208 32569 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515492304271-32569-0/minicluster-data/ts-0-root
uuid: "c39cbdd68e1f4e5a9f319d842c688300"
format_stamp: "Formatted at 2026-08-12 06:18:17 on dist-test-slave-q9h9"
I20260812 06:18:17.500288 32569 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515492304271-32569-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515492304271-32569-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515492304271-32569-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:17.509496 32569 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:17.509805 32569 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:17.510092 32569 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:17.510509 32569 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:17.510545 32569 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:17.510584 32569 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:17.510612 32569 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:17.514654 32569 rpc_server.cc:307] RPC server started. Bound to: 127.31.206.65:33573
I20260812 06:18:17.515127   785 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.31.206.65:33573 every 8 connection(s)
I20260812 06:18:17.523509   786 heartbeater.cc:344] Connected to a master server at 127.31.206.126:40225
I20260812 06:18:17.523604   786 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:17.523808   786 heartbeater.cc:507] Master 127.31.206.126:40225 requested a full tablet report, sending...
I20260812 06:18:17.524382   543 ts_manager.cc:194] Registered new tserver with Master: c39cbdd68e1f4e5a9f319d842c688300 (127.31.206.65:33573)
I20260812 06:18:17.525022 32569 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.009834197s
I20260812 06:18:17.525085   543 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:39030
I20260812 06:18:17.531070   543 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:39040:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:18:17.538924   719 tablet_service.cc:1511] Processing CreateTablet for tablet 19ac1f9a561748e8902d413f44dc75a7 (DEFAULT_TABLE table=heavy-update-compaction-test [id=8853eec3fff54202aa7647391d88e655]), partition=
I20260812 06:18:17.539161   719 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 19ac1f9a561748e8902d413f44dc75a7. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:17.540957   807 tablet_bootstrap.cc:492] T 19ac1f9a561748e8902d413f44dc75a7 P c39cbdd68e1f4e5a9f319d842c688300: Bootstrap starting.
I20260812 06:18:17.541836   807 tablet_bootstrap.cc:654] T 19ac1f9a561748e8902d413f44dc75a7 P c39cbdd68e1f4e5a9f319d842c688300: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:17.542820   807 tablet_bootstrap.cc:492] T 19ac1f9a561748e8902d413f44dc75a7 P c39cbdd68e1f4e5a9f319d842c688300: No bootstrap required, opened a new log
I20260812 06:18:17.542892   807 ts_tablet_manager.cc:1403] T 19ac1f9a561748e8902d413f44dc75a7 P c39cbdd68e1f4e5a9f319d842c688300: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:18:17.543262   807 raft_consensus.cc:359] T 19ac1f9a561748e8902d413f44dc75a7 P c39cbdd68e1f4e5a9f319d842c688300 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c39cbdd68e1f4e5a9f319d842c688300" member_type: VOTER last_known_addr { host: "127.31.206.65" port: 33573 } }
I20260812 06:18:17.543388   807 raft_consensus.cc:385] T 19ac1f9a561748e8902d413f44dc75a7 P c39cbdd68e1f4e5a9f319d842c688300 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:17.543429   807 raft_consensus.cc:740] T 19ac1f9a561748e8902d413f44dc75a7 P c39cbdd68e1f4e5a9f319d842c688300 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: c39cbdd68e1f4e5a9f319d842c688300, State: Initialized, Role: FOLLOWER
I20260812 06:18:17.543562   807 consensus_queue.cc:260] T 19ac1f9a561748e8902d413f44dc75a7 P c39cbdd68e1f4e5a9f319d842c688300 [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: "c39cbdd68e1f4e5a9f319d842c688300" member_type: VOTER last_known_addr { host: "127.31.206.65" port: 33573 } }
I20260812 06:18:17.543637   807 raft_consensus.cc:399] T 19ac1f9a561748e8902d413f44dc75a7 P c39cbdd68e1f4e5a9f319d842c688300 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:17.543673   807 raft_consensus.cc:493] T 19ac1f9a561748e8902d413f44dc75a7 P c39cbdd68e1f4e5a9f319d842c688300 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:17.543721   807 raft_consensus.cc:3060] T 19ac1f9a561748e8902d413f44dc75a7 P c39cbdd68e1f4e5a9f319d842c688300 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:17.544497   807 raft_consensus.cc:515] T 19ac1f9a561748e8902d413f44dc75a7 P c39cbdd68e1f4e5a9f319d842c688300 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c39cbdd68e1f4e5a9f319d842c688300" member_type: VOTER last_known_addr { host: "127.31.206.65" port: 33573 } }
I20260812 06:18:17.544629   807 leader_election.cc:304] T 19ac1f9a561748e8902d413f44dc75a7 P c39cbdd68e1f4e5a9f319d842c688300 [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: c39cbdd68e1f4e5a9f319d842c688300; no voters: 
I20260812 06:18:17.544806   807 leader_election.cc:290] T 19ac1f9a561748e8902d413f44dc75a7 P c39cbdd68e1f4e5a9f319d842c688300 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:17.544902   809 raft_consensus.cc:2804] T 19ac1f9a561748e8902d413f44dc75a7 P c39cbdd68e1f4e5a9f319d842c688300 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:17.545095   809 raft_consensus.cc:697] T 19ac1f9a561748e8902d413f44dc75a7 P c39cbdd68e1f4e5a9f319d842c688300 [term 1 LEADER]: Becoming Leader. State: Replica: c39cbdd68e1f4e5a9f319d842c688300, State: Running, Role: LEADER
I20260812 06:18:17.545137   786 heartbeater.cc:499] Master 127.31.206.126:40225 was elected leader, sending a full tablet report...
I20260812 06:18:17.545101   807 ts_tablet_manager.cc:1434] T 19ac1f9a561748e8902d413f44dc75a7 P c39cbdd68e1f4e5a9f319d842c688300: Time spent starting tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:17.545277   809 consensus_queue.cc:237] T 19ac1f9a561748e8902d413f44dc75a7 P c39cbdd68e1f4e5a9f319d842c688300 [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: "c39cbdd68e1f4e5a9f319d842c688300" member_type: VOTER last_known_addr { host: "127.31.206.65" port: 33573 } }
I20260812 06:18:17.546485   543 catalog_manager.cc:5719] T 19ac1f9a561748e8902d413f44dc75a7 P c39cbdd68e1f4e5a9f319d842c688300 reported cstate change: term changed from 0 to 1, leader changed from <none> to c39cbdd68e1f4e5a9f319d842c688300 (127.31.206.65). New cstate: current_term: 1 leader_uuid: "c39cbdd68e1f4e5a9f319d842c688300" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c39cbdd68e1f4e5a9f319d842c688300" member_type: VOTER last_known_addr { host: "127.31.206.65" port: 33573 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:17.599198 32569 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.049s	user 0.018s	sys 0.003s
I20260812 06:18:17.765705   788 maintenance_manager.cc:419] P c39cbdd68e1f4e5a9f319d842c688300: Scheduling FlushMRSOp(19ac1f9a561748e8902d413f44dc75a7): perf score=23.023690
I20260812 06:18:17.927834   667 maintenance_manager.cc:643] P c39cbdd68e1f4e5a9f319d842c688300: FlushMRSOp(19ac1f9a561748e8902d413f44dc75a7) complete. Timing: real 0.162s	user 0.119s	sys 0.039s Metrics: {"bytes_written":13045918,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":85,"dirs.run_cpu_time_us":198,"dirs.run_wall_time_us":743,"drs_written":1,"lbm_read_time_us":35,"lbm_reads_lt_1ms":4,"lbm_write_time_us":44249,"lbm_writes_lt_1ms":875,"mutex_wait_us":198,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"update_count":1590}
I20260812 06:18:17.928484   788 maintenance_manager.cc:419] P c39cbdd68e1f4e5a9f319d842c688300: Scheduling LogGCOp(19ac1f9a561748e8902d413f44dc75a7): free 20743880 bytes of WAL
I20260812 06:18:17.928706   667 log_reader.cc:385] T 19ac1f9a561748e8902d413f44dc75a7: removed 2 log segments from log reader
I20260812 06:18:17.928789   667 log.cc:1079] T 19ac1f9a561748e8902d413f44dc75a7 P c39cbdd68e1f4e5a9f319d842c688300: Deleting log segment in path: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515492304271-32569-0/minicluster-data/ts-0-root/wals/19ac1f9a561748e8902d413f44dc75a7/wal-000000001 (ops 1-6)
I20260812 06:18:17.928838   667 log.cc:1079] T 19ac1f9a561748e8902d413f44dc75a7 P c39cbdd68e1f4e5a9f319d842c688300: Deleting log segment in path: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515492304271-32569-0/minicluster-data/ts-0-root/wals/19ac1f9a561748e8902d413f44dc75a7/wal-000000002 (ops 7-11)
I20260812 06:18:17.933701   667 maintenance_manager.cc:643] P c39cbdd68e1f4e5a9f319d842c688300: LogGCOp(19ac1f9a561748e8902d413f44dc75a7) complete. Timing: real 0.005s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:18:17.934051   788 maintenance_manager.cc:419] P c39cbdd68e1f4e5a9f319d842c688300: Scheduling UndoDeltaBlockGCOp(19ac1f9a561748e8902d413f44dc75a7): 20513815 bytes on disk
I20260812 06:18:17.934473   667 maintenance_manager.cc:643] P c39cbdd68e1f4e5a9f319d842c688300: UndoDeltaBlockGCOp(19ac1f9a561748e8902d413f44dc75a7) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":68,"lbm_reads_lt_1ms":4}
I20260812 06:18:17.934872   788 maintenance_manager.cc:419] P c39cbdd68e1f4e5a9f319d842c688300: Scheduling FlushDeltaMemStoresOp(19ac1f9a561748e8902d413f44dc75a7): perf score=2.188937
I20260812 06:18:17.944909   667 maintenance_manager.cc:643] P c39cbdd68e1f4e5a9f319d842c688300: FlushDeltaMemStoresOp(19ac1f9a561748e8902d413f44dc75a7) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4020613,"delete_count":0,"lbm_write_time_us":3652,"lbm_writes_lt_1ms":101,"reinsert_count":0,"update_count":490}
I20260812 06:18:17.945262   788 maintenance_manager.cc:419] P c39cbdd68e1f4e5a9f319d842c688300: Scheduling FlushDeltaMemStoresOp(19ac1f9a561748e8902d413f44dc75a7): perf score=2.188937
I20260812 06:18:17.953397   667 maintenance_manager.cc:643] P c39cbdd68e1f4e5a9f319d842c688300: FlushDeltaMemStoresOp(19ac1f9a561748e8902d413f44dc75a7) complete. Timing: real 0.008s	user 0.003s	sys 0.004s Metrics: {"bytes_written":3446255,"delete_count":0,"lbm_write_time_us":3027,"lbm_writes_lt_1ms":87,"reinsert_count":0,"update_count":420}
I20260812 06:18:17.953711   788 maintenance_manager.cc:419] P c39cbdd68e1f4e5a9f319d842c688300: Scheduling MajorDeltaCompactionOp(19ac1f9a561748e8902d413f44dc75a7): perf score=1.000000
I20260812 06:18:18.118813   667 maintenance_manager.cc:643] P c39cbdd68e1f4e5a9f319d842c688300: MajorDeltaCompactionOp(19ac1f9a561748e8902d413f44dc75a7) complete. Timing: real 0.165s	user 0.129s	sys 0.036s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815781,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":625,"lbm_read_time_us":13590,"lbm_reads_lt_1ms":569,"lbm_write_time_us":27583,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10624,"thread_start_us":282,"threads_started":5,"update_count":2500}
I20260812 06:18:18.119336   788 maintenance_manager.cc:419] P c39cbdd68e1f4e5a9f319d842c688300: Scheduling FlushDeltaMemStoresOp(19ac1f9a561748e8902d413f44dc75a7): perf score=14.095187
I20260812 06:18:18.175889   667 maintenance_manager.cc:643] P c39cbdd68e1f4e5a9f319d842c688300: FlushDeltaMemStoresOp(19ac1f9a561748e8902d413f44dc75a7) complete. Timing: real 0.056s	user 0.022s	sys 0.031s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":25735,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":400,"reinsert_count":0,"update_count":2000}
I20260812 06:18:18.176712   788 maintenance_manager.cc:419] P c39cbdd68e1f4e5a9f319d842c688300: Scheduling FlushDeltaMemStoresOp(19ac1f9a561748e8902d413f44dc75a7): perf score=2.188937
I20260812 06:18:18.199680   667 maintenance_manager.cc:643] P c39cbdd68e1f4e5a9f319d842c688300: FlushDeltaMemStoresOp(19ac1f9a561748e8902d413f44dc75a7) complete. Timing: real 0.023s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5149,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:18.200115   788 maintenance_manager.cc:419] P c39cbdd68e1f4e5a9f319d842c688300: Scheduling FlushDeltaMemStoresOp(19ac1f9a561748e8902d413f44dc75a7): perf score=2.188937
I20260812 06:18:18.211160   667 maintenance_manager.cc:643] P c39cbdd68e1f4e5a9f319d842c688300: FlushDeltaMemStoresOp(19ac1f9a561748e8902d413f44dc75a7) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4379,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:18.211723   788 maintenance_manager.cc:419] P c39cbdd68e1f4e5a9f319d842c688300: Scheduling MajorDeltaCompactionOp(19ac1f9a561748e8902d413f44dc75a7): perf score=1.000000
I20260812 06:18:18.365178   667 maintenance_manager.cc:643] P c39cbdd68e1f4e5a9f319d842c688300: MajorDeltaCompactionOp(19ac1f9a561748e8902d413f44dc75a7) complete. Timing: real 0.153s	user 0.117s	sys 0.035s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918216,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":205,"lbm_read_time_us":12334,"lbm_reads_lt_1ms":673,"lbm_write_time_us":28921,"lbm_writes_lt_1ms":643,"mutex_wait_us":21,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":23168,"update_count":3000}
I20260812 06:18:18.365736   788 maintenance_manager.cc:419] P c39cbdd68e1f4e5a9f319d842c688300: Scheduling FlushDeltaMemStoresOp(19ac1f9a561748e8902d413f44dc75a7): perf score=14.095187
I20260812 06:18:18.410714   667 maintenance_manager.cc:643] P c39cbdd68e1f4e5a9f319d842c688300: FlushDeltaMemStoresOp(19ac1f9a561748e8902d413f44dc75a7) complete. Timing: real 0.045s	user 0.033s	sys 0.011s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20310,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:18.411172   788 maintenance_manager.cc:419] P c39cbdd68e1f4e5a9f319d842c688300: Scheduling FlushDeltaMemStoresOp(19ac1f9a561748e8902d413f44dc75a7): perf score=2.188937
I20260812 06:18:18.427691   667 maintenance_manager.cc:643] P c39cbdd68e1f4e5a9f319d842c688300: FlushDeltaMemStoresOp(19ac1f9a561748e8902d413f44dc75a7) complete. Timing: real 0.016s	user 0.003s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4964,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:18.428880   788 maintenance_manager.cc:419] P c39cbdd68e1f4e5a9f319d842c688300: Scheduling MajorDeltaCompactionOp(19ac1f9a561748e8902d413f44dc75a7): perf score=1.000000
I20260812 06:18:18.579898   667 maintenance_manager.cc:643] P c39cbdd68e1f4e5a9f319d842c688300: MajorDeltaCompactionOp(19ac1f9a561748e8902d413f44dc75a7) complete. Timing: real 0.151s	user 0.115s	sys 0.035s 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":179,"lbm_read_time_us":11157,"lbm_reads_lt_1ms":564,"lbm_write_time_us":27167,"lbm_writes_lt_1ms":543,"mutex_wait_us":23,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":58752,"update_count":2500}
I20260812 06:18:18.580492   788 maintenance_manager.cc:419] P c39cbdd68e1f4e5a9f319d842c688300: Scheduling FlushDeltaMemStoresOp(19ac1f9a561748e8902d413f44dc75a7): perf score=14.095187
I20260812 06:18:18.641667   667 maintenance_manager.cc:643] P c39cbdd68e1f4e5a9f319d842c688300: FlushDeltaMemStoresOp(19ac1f9a561748e8902d413f44dc75a7) complete. Timing: real 0.061s	user 0.034s	sys 0.015s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":22283,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:18.642168   788 maintenance_manager.cc:419] P c39cbdd68e1f4e5a9f319d842c688300: Scheduling FlushDeltaMemStoresOp(19ac1f9a561748e8902d413f44dc75a7): perf score=2.188937
I20260812 06:18:18.651324   667 maintenance_manager.cc:643] P c39cbdd68e1f4e5a9f319d842c688300: FlushDeltaMemStoresOp(19ac1f9a561748e8902d413f44dc75a7) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3545,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:18.651862   788 maintenance_manager.cc:419] P c39cbdd68e1f4e5a9f319d842c688300: Scheduling MajorDeltaCompactionOp(19ac1f9a561748e8902d413f44dc75a7): perf score=1.000000
I20260812 06:18:18.819914   667 maintenance_manager.cc:643] P c39cbdd68e1f4e5a9f319d842c688300: MajorDeltaCompactionOp(19ac1f9a561748e8902d413f44dc75a7) complete. Timing: real 0.168s	user 0.086s	sys 0.080s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":586,"lbm_read_time_us":11688,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29017,"lbm_writes_lt_1ms":543,"mutex_wait_us":287,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8832,"update_count":2500}
I20260812 06:18:18.820420   788 maintenance_manager.cc:419] P c39cbdd68e1f4e5a9f319d842c688300: Scheduling FlushDeltaMemStoresOp(19ac1f9a561748e8902d413f44dc75a7): perf score=14.095187
I20260812 06:18:18.875309   667 maintenance_manager.cc:643] P c39cbdd68e1f4e5a9f319d842c688300: FlushDeltaMemStoresOp(19ac1f9a561748e8902d413f44dc75a7) complete. Timing: real 0.055s	user 0.039s	sys 0.007s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":20726,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2000}
I20260812 06:18:18.875865   788 maintenance_manager.cc:419] P c39cbdd68e1f4e5a9f319d842c688300: Scheduling FlushDeltaMemStoresOp(19ac1f9a561748e8902d413f44dc75a7): perf score=2.188937
I20260812 06:18:18.891793   667 maintenance_manager.cc:643] P c39cbdd68e1f4e5a9f319d842c688300: FlushDeltaMemStoresOp(19ac1f9a561748e8902d413f44dc75a7) complete. Timing: real 0.016s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6103,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:18.892344   788 maintenance_manager.cc:419] P c39cbdd68e1f4e5a9f319d842c688300: Scheduling MajorDeltaCompactionOp(19ac1f9a561748e8902d413f44dc75a7): perf score=1.000000
I20260812 06:18:19.055930   667 maintenance_manager.cc:643] P c39cbdd68e1f4e5a9f319d842c688300: MajorDeltaCompactionOp(19ac1f9a561748e8902d413f44dc75a7) complete. Timing: real 0.163s	user 0.104s	sys 0.059s 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":633,"lbm_read_time_us":13071,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27069,"lbm_writes_lt_1ms":543,"mutex_wait_us":302,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":21632,"update_count":2500}
I20260812 06:18:19.056483   788 maintenance_manager.cc:419] P c39cbdd68e1f4e5a9f319d842c688300: Scheduling FlushDeltaMemStoresOp(19ac1f9a561748e8902d413f44dc75a7): perf score=14.095187
I20260812 06:18:19.108103   667 maintenance_manager.cc:643] P c39cbdd68e1f4e5a9f319d842c688300: FlushDeltaMemStoresOp(19ac1f9a561748e8902d413f44dc75a7) complete. Timing: real 0.051s	user 0.028s	sys 0.022s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19037,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:19.108628   788 maintenance_manager.cc:419] P c39cbdd68e1f4e5a9f319d842c688300: Scheduling FlushDeltaMemStoresOp(19ac1f9a561748e8902d413f44dc75a7): perf score=2.188937
I20260812 06:18:19.118312   667 maintenance_manager.cc:643] P c39cbdd68e1f4e5a9f319d842c688300: FlushDeltaMemStoresOp(19ac1f9a561748e8902d413f44dc75a7) complete. Timing: real 0.009s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3770,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:19.118759   788 maintenance_manager.cc:419] P c39cbdd68e1f4e5a9f319d842c688300: Scheduling FlushMRSOp(19ac1f9a561748e8902d413f44dc75a7): perf score=1.000000
I20260812 06:18:19.146577   667 maintenance_manager.cc:643] P c39cbdd68e1f4e5a9f319d842c688300: FlushMRSOp(19ac1f9a561748e8902d413f44dc75a7) complete. Timing: real 0.028s	user 0.023s	sys 0.004s Metrics: {"bytes_written":1275444,"cfile_init":1,"dirs.queue_time_us":58,"dirs.run_cpu_time_us":227,"dirs.run_wall_time_us":985,"drs_written":1,"lbm_read_time_us":36,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1399,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:18:19.147182   788 maintenance_manager.cc:419] P c39cbdd68e1f4e5a9f319d842c688300: Scheduling UndoDeltaBlockGCOp(19ac1f9a561748e8902d413f44dc75a7): 482 bytes on disk
I20260812 06:18:19.147683   667 maintenance_manager.cc:643] P c39cbdd68e1f4e5a9f319d842c688300: UndoDeltaBlockGCOp(19ac1f9a561748e8902d413f44dc75a7) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4}
I20260812 06:18:19.148149   788 maintenance_manager.cc:419] P c39cbdd68e1f4e5a9f319d842c688300: Scheduling MajorDeltaCompactionOp(19ac1f9a561748e8902d413f44dc75a7): perf score=1.000000
I20260812 06:18:19.315018   667 maintenance_manager.cc:643] P c39cbdd68e1f4e5a9f319d842c688300: MajorDeltaCompactionOp(19ac1f9a561748e8902d413f44dc75a7) complete. Timing: real 0.167s	user 0.103s	sys 0.063s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":972,"lbm_read_time_us":13013,"lbm_reads_lt_1ms":564,"lbm_write_time_us":27063,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:18:19.315596   788 maintenance_manager.cc:419] P c39cbdd68e1f4e5a9f319d842c688300: Scheduling LogGCOp(19ac1f9a561748e8902d413f44dc75a7): free 124710260 bytes of WAL
I20260812 06:18:19.315892   667 log_reader.cc:385] T 19ac1f9a561748e8902d413f44dc75a7: removed 12 log segments from log reader
I20260812 06:18:19.315958   667 log.cc:1079] T 19ac1f9a561748e8902d413f44dc75a7 P c39cbdd68e1f4e5a9f319d842c688300: Deleting log segment in path: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515492304271-32569-0/minicluster-data/ts-0-root/wals/19ac1f9a561748e8902d413f44dc75a7/wal-000000003 (ops 12-16)
I20260812 06:18:19.316012   667 log.cc:1079] T 19ac1f9a561748e8902d413f44dc75a7 P c39cbdd68e1f4e5a9f319d842c688300: Deleting log segment in path: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515492304271-32569-0/minicluster-data/ts-0-root/wals/19ac1f9a561748e8902d413f44dc75a7/wal-000000004 (ops 17-21)
I20260812 06:18:19.316051   667 log.cc:1079] T 19ac1f9a561748e8902d413f44dc75a7 P c39cbdd68e1f4e5a9f319d842c688300: Deleting log segment in path: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515492304271-32569-0/minicluster-data/ts-0-root/wals/19ac1f9a561748e8902d413f44dc75a7/wal-000000005 (ops 22-26)
I20260812 06:18:19.316087   667 log.cc:1079] T 19ac1f9a561748e8902d413f44dc75a7 P c39cbdd68e1f4e5a9f319d842c688300: Deleting log segment in path: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515492304271-32569-0/minicluster-data/ts-0-root/wals/19ac1f9a561748e8902d413f44dc75a7/wal-000000006 (ops 27-31)
I20260812 06:18:19.316123   667 log.cc:1079] T 19ac1f9a561748e8902d413f44dc75a7 P c39cbdd68e1f4e5a9f319d842c688300: Deleting log segment in path: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515492304271-32569-0/minicluster-data/ts-0-root/wals/19ac1f9a561748e8902d413f44dc75a7/wal-000000007 (ops 32-36)
I20260812 06:18:19.316159   667 log.cc:1079] T 19ac1f9a561748e8902d413f44dc75a7 P c39cbdd68e1f4e5a9f319d842c688300: Deleting log segment in path: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515492304271-32569-0/minicluster-data/ts-0-root/wals/19ac1f9a561748e8902d413f44dc75a7/wal-000000008 (ops 37-41)
I20260812 06:18:19.316193   667 log.cc:1079] T 19ac1f9a561748e8902d413f44dc75a7 P c39cbdd68e1f4e5a9f319d842c688300: Deleting log segment in path: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515492304271-32569-0/minicluster-data/ts-0-root/wals/19ac1f9a561748e8902d413f44dc75a7/wal-000000009 (ops 42-46)
I20260812 06:18:19.316247   667 log.cc:1079] T 19ac1f9a561748e8902d413f44dc75a7 P c39cbdd68e1f4e5a9f319d842c688300: Deleting log segment in path: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515492304271-32569-0/minicluster-data/ts-0-root/wals/19ac1f9a561748e8902d413f44dc75a7/wal-000000010 (ops 47-51)
I20260812 06:18:19.316293   667 log.cc:1079] T 19ac1f9a561748e8902d413f44dc75a7 P c39cbdd68e1f4e5a9f319d842c688300: Deleting log segment in path: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515492304271-32569-0/minicluster-data/ts-0-root/wals/19ac1f9a561748e8902d413f44dc75a7/wal-000000011 (ops 52-56)
I20260812 06:18:19.316330   667 log.cc:1079] T 19ac1f9a561748e8902d413f44dc75a7 P c39cbdd68e1f4e5a9f319d842c688300: Deleting log segment in path: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515492304271-32569-0/minicluster-data/ts-0-root/wals/19ac1f9a561748e8902d413f44dc75a7/wal-000000012 (ops 57-61)
I20260812 06:18:19.316370   667 log.cc:1079] T 19ac1f9a561748e8902d413f44dc75a7 P c39cbdd68e1f4e5a9f319d842c688300: Deleting log segment in path: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515492304271-32569-0/minicluster-data/ts-0-root/wals/19ac1f9a561748e8902d413f44dc75a7/wal-000000013 (ops 62-66)
I20260812 06:18:19.316406   667 log.cc:1079] T 19ac1f9a561748e8902d413f44dc75a7 P c39cbdd68e1f4e5a9f319d842c688300: Deleting log segment in path: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515492304271-32569-0/minicluster-data/ts-0-root/wals/19ac1f9a561748e8902d413f44dc75a7/wal-000000014 (ops 67-71)
I20260812 06:18:19.347237   667 maintenance_manager.cc:643] P c39cbdd68e1f4e5a9f319d842c688300: LogGCOp(19ac1f9a561748e8902d413f44dc75a7) complete. Timing: real 0.031s	user 0.000s	sys 0.030s Metrics: {}
I20260812 06:18:19.347622   788 maintenance_manager.cc:419] P c39cbdd68e1f4e5a9f319d842c688300: Scheduling FlushDeltaMemStoresOp(19ac1f9a561748e8902d413f44dc75a7): perf score=18.063937
I20260812 06:18:19.424168   667 maintenance_manager.cc:643] P c39cbdd68e1f4e5a9f319d842c688300: FlushDeltaMemStoresOp(19ac1f9a561748e8902d413f44dc75a7) complete. Timing: real 0.076s	user 0.043s	sys 0.031s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":29365,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:19.424726   788 maintenance_manager.cc:419] P c39cbdd68e1f4e5a9f319d842c688300: Scheduling FlushDeltaMemStoresOp(19ac1f9a561748e8902d413f44dc75a7): perf score=3.181125
I20260812 06:18:19.449224   667 maintenance_manager.cc:643] P c39cbdd68e1f4e5a9f319d842c688300: FlushDeltaMemStoresOp(19ac1f9a561748e8902d413f44dc75a7) complete. Timing: real 0.024s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4512902,"delete_count":0,"lbm_write_time_us":5393,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:19.449616   788 maintenance_manager.cc:419] P c39cbdd68e1f4e5a9f319d842c688300: Scheduling FlushDeltaMemStoresOp(19ac1f9a561748e8902d413f44dc75a7): perf score=2.188937
I20260812 06:18:19.458372   667 maintenance_manager.cc:643] P c39cbdd68e1f4e5a9f319d842c688300: FlushDeltaMemStoresOp(19ac1f9a561748e8902d413f44dc75a7) complete. Timing: real 0.009s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3297,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:19.458743   788 maintenance_manager.cc:419] P c39cbdd68e1f4e5a9f319d842c688300: Scheduling MajorDeltaCompactionOp(19ac1f9a561748e8902d413f44dc75a7): perf score=1.000000
I20260812 06:18:19.683396   667 maintenance_manager.cc:643] P c39cbdd68e1f4e5a9f319d842c688300: MajorDeltaCompactionOp(19ac1f9a561748e8902d413f44dc75a7) complete. Timing: real 0.225s	user 0.137s	sys 0.087s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":33020617,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1094,"lbm_read_time_us":15610,"lbm_reads_lt_1ms":773,"lbm_write_time_us":36722,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"update_count":3500}
I20260812 06:18:19.683876   788 maintenance_manager.cc:419] P c39cbdd68e1f4e5a9f319d842c688300: Scheduling FlushDeltaMemStoresOp(19ac1f9a561748e8902d413f44dc75a7): perf score=18.063937
I20260812 06:18:19.764319   667 maintenance_manager.cc:643] P c39cbdd68e1f4e5a9f319d842c688300: FlushDeltaMemStoresOp(19ac1f9a561748e8902d413f44dc75a7) complete. Timing: real 0.080s	user 0.044s	sys 0.027s Metrics: {"bytes_written":20512314,"delete_count":0,"lbm_write_time_us":40432,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":501,"reinsert_count":0,"update_count":2500}
I20260812 06:18:19.764884   788 maintenance_manager.cc:419] P c39cbdd68e1f4e5a9f319d842c688300: Scheduling FlushDeltaMemStoresOp(19ac1f9a561748e8902d413f44dc75a7): perf score=2.188937
I20260812 06:18:19.779997   667 maintenance_manager.cc:643] P c39cbdd68e1f4e5a9f319d842c688300: FlushDeltaMemStoresOp(19ac1f9a561748e8902d413f44dc75a7) complete. Timing: real 0.015s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5476,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:19.780553   788 maintenance_manager.cc:419] P c39cbdd68e1f4e5a9f319d842c688300: Scheduling MajorDeltaCompactionOp(19ac1f9a561748e8902d413f44dc75a7): perf score=1.000000
I20260812 06:18:20.021003   667 maintenance_manager.cc:643] P c39cbdd68e1f4e5a9f319d842c688300: MajorDeltaCompactionOp(19ac1f9a561748e8902d413f44dc75a7) complete. Timing: real 0.240s	user 0.139s	sys 0.098s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918096,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":216,"lbm_read_time_us":16596,"lbm_reads_lt_1ms":664,"lbm_write_time_us":38429,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2048,"update_count":3000}
I20260812 06:18:20.021603   788 maintenance_manager.cc:419] P c39cbdd68e1f4e5a9f319d842c688300: Scheduling FlushDeltaMemStoresOp(19ac1f9a561748e8902d413f44dc75a7): perf score=22.032687
I20260812 06:18:20.099453   667 maintenance_manager.cc:643] P c39cbdd68e1f4e5a9f319d842c688300: FlushDeltaMemStoresOp(19ac1f9a561748e8902d413f44dc75a7) complete. Timing: real 0.078s	user 0.050s	sys 0.023s Metrics: {"bytes_written":24614722,"delete_count":0,"lbm_write_time_us":35481,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":602,"reinsert_count":0,"update_count":3000}
I20260812 06:18:20.099972   788 maintenance_manager.cc:419] P c39cbdd68e1f4e5a9f319d842c688300: Scheduling FlushDeltaMemStoresOp(19ac1f9a561748e8902d413f44dc75a7): perf score=2.188937
I20260812 06:18:20.113725   667 maintenance_manager.cc:643] P c39cbdd68e1f4e5a9f319d842c688300: FlushDeltaMemStoresOp(19ac1f9a561748e8902d413f44dc75a7) complete. Timing: real 0.014s	user 0.004s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5356,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:20.114339   788 maintenance_manager.cc:419] P c39cbdd68e1f4e5a9f319d842c688300: Scheduling MajorDeltaCompactionOp(19ac1f9a561748e8902d413f44dc75a7): perf score=1.000000
I20260812 06:18:20.350175   667 maintenance_manager.cc:643] P c39cbdd68e1f4e5a9f319d842c688300: MajorDeltaCompactionOp(19ac1f9a561748e8902d413f44dc75a7) complete. Timing: real 0.236s	user 0.144s	sys 0.080s Metrics: {"cfile_cache_miss":732,"cfile_cache_miss_bytes":33020504,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":527,"lbm_read_time_us":17962,"lbm_reads_lt_1ms":764,"lbm_write_time_us":40878,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":3500}
I20260812 06:18:20.350867   788 maintenance_manager.cc:419] P c39cbdd68e1f4e5a9f319d842c688300: Scheduling FlushDeltaMemStoresOp(19ac1f9a561748e8902d413f44dc75a7): perf score=22.032687
I20260812 06:18:20.432348   667 maintenance_manager.cc:643] P c39cbdd68e1f4e5a9f319d842c688300: FlushDeltaMemStoresOp(19ac1f9a561748e8902d413f44dc75a7) complete. Timing: real 0.081s	user 0.024s	sys 0.044s Metrics: {"bytes_written":24614719,"delete_count":0,"lbm_write_time_us":31576,"lbm_writes_lt_1ms":603,"reinsert_count":0,"update_count":3000}
I20260812 06:18:20.432814   788 maintenance_manager.cc:419] P c39cbdd68e1f4e5a9f319d842c688300: Scheduling FlushDeltaMemStoresOp(19ac1f9a561748e8902d413f44dc75a7): perf score=6.157687
I20260812 06:18:20.454612   667 maintenance_manager.cc:643] P c39cbdd68e1f4e5a9f319d842c688300: FlushDeltaMemStoresOp(19ac1f9a561748e8902d413f44dc75a7) complete. Timing: real 0.022s	user 0.005s	sys 0.016s Metrics: {"bytes_written":8205077,"delete_count":0,"lbm_write_time_us":9363,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:18:20.455205   788 maintenance_manager.cc:419] P c39cbdd68e1f4e5a9f319d842c688300: Scheduling FlushMRSOp(19ac1f9a561748e8902d413f44dc75a7): perf score=1.000000
I20260812 06:18:20.502203   667 maintenance_manager.cc:643] P c39cbdd68e1f4e5a9f319d842c688300: FlushMRSOp(19ac1f9a561748e8902d413f44dc75a7) complete. Timing: real 0.047s	user 0.027s	sys 0.000s Metrics: {"bytes_written":1193507,"cfile_init":1,"dirs.queue_time_us":60,"dirs.run_cpu_time_us":199,"dirs.run_wall_time_us":946,"drs_written":1,"lbm_read_time_us":41,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1468,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:18:20.502911   788 maintenance_manager.cc:419] P c39cbdd68e1f4e5a9f319d842c688300: Scheduling LogGCOp(19ac1f9a561748e8902d413f44dc75a7): free 124257305 bytes of WAL
I20260812 06:18:20.503149   667 log_reader.cc:385] T 19ac1f9a561748e8902d413f44dc75a7: removed 12 log segments from log reader
I20260812 06:18:20.503211   667 log.cc:1079] T 19ac1f9a561748e8902d413f44dc75a7 P c39cbdd68e1f4e5a9f319d842c688300: Deleting log segment in path: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515492304271-32569-0/minicluster-data/ts-0-root/wals/19ac1f9a561748e8902d413f44dc75a7/wal-000000015 (ops 72-76)
I20260812 06:18:20.503235   667 log.cc:1079] T 19ac1f9a561748e8902d413f44dc75a7 P c39cbdd68e1f4e5a9f319d842c688300: Deleting log segment in path: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515492304271-32569-0/minicluster-data/ts-0-root/wals/19ac1f9a561748e8902d413f44dc75a7/wal-000000016 (ops 77-81)
I20260812 06:18:20.503252   667 log.cc:1079] T 19ac1f9a561748e8902d413f44dc75a7 P c39cbdd68e1f4e5a9f319d842c688300: Deleting log segment in path: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515492304271-32569-0/minicluster-data/ts-0-root/wals/19ac1f9a561748e8902d413f44dc75a7/wal-000000017 (ops 82-86)
I20260812 06:18:20.503273   667 log.cc:1079] T 19ac1f9a561748e8902d413f44dc75a7 P c39cbdd68e1f4e5a9f319d842c688300: Deleting log segment in path: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515492304271-32569-0/minicluster-data/ts-0-root/wals/19ac1f9a561748e8902d413f44dc75a7/wal-000000018 (ops 87-90)
I20260812 06:18:20.503304   667 log.cc:1079] T 19ac1f9a561748e8902d413f44dc75a7 P c39cbdd68e1f4e5a9f319d842c688300: Deleting log segment in path: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515492304271-32569-0/minicluster-data/ts-0-root/wals/19ac1f9a561748e8902d413f44dc75a7/wal-000000019 (ops 91-95)
I20260812 06:18:20.503334   667 log.cc:1079] T 19ac1f9a561748e8902d413f44dc75a7 P c39cbdd68e1f4e5a9f319d842c688300: Deleting log segment in path: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515492304271-32569-0/minicluster-data/ts-0-root/wals/19ac1f9a561748e8902d413f44dc75a7/wal-000000020 (ops 96-100)
I20260812 06:18:20.503366   667 log.cc:1079] T 19ac1f9a561748e8902d413f44dc75a7 P c39cbdd68e1f4e5a9f319d842c688300: Deleting log segment in path: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515492304271-32569-0/minicluster-data/ts-0-root/wals/19ac1f9a561748e8902d413f44dc75a7/wal-000000021 (ops 101-105)
I20260812 06:18:20.503397   667 log.cc:1079] T 19ac1f9a561748e8902d413f44dc75a7 P c39cbdd68e1f4e5a9f319d842c688300: Deleting log segment in path: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515492304271-32569-0/minicluster-data/ts-0-root/wals/19ac1f9a561748e8902d413f44dc75a7/wal-000000022 (ops 106-110)
I20260812 06:18:20.503429   667 log.cc:1079] T 19ac1f9a561748e8902d413f44dc75a7 P c39cbdd68e1f4e5a9f319d842c688300: Deleting log segment in path: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515492304271-32569-0/minicluster-data/ts-0-root/wals/19ac1f9a561748e8902d413f44dc75a7/wal-000000023 (ops 111-115)
I20260812 06:18:20.503460   667 log.cc:1079] T 19ac1f9a561748e8902d413f44dc75a7 P c39cbdd68e1f4e5a9f319d842c688300: Deleting log segment in path: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515492304271-32569-0/minicluster-data/ts-0-root/wals/19ac1f9a561748e8902d413f44dc75a7/wal-000000024 (ops 116-120)
I20260812 06:18:20.503490   667 log.cc:1079] T 19ac1f9a561748e8902d413f44dc75a7 P c39cbdd68e1f4e5a9f319d842c688300: Deleting log segment in path: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515492304271-32569-0/minicluster-data/ts-0-root/wals/19ac1f9a561748e8902d413f44dc75a7/wal-000000025 (ops 121-125)
I20260812 06:18:20.503521   667 log.cc:1079] T 19ac1f9a561748e8902d413f44dc75a7 P c39cbdd68e1f4e5a9f319d842c688300: Deleting log segment in path: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515492304271-32569-0/minicluster-data/ts-0-root/wals/19ac1f9a561748e8902d413f44dc75a7/wal-000000026 (ops 126-130)
I20260812 06:18:20.527046   667 maintenance_manager.cc:643] P c39cbdd68e1f4e5a9f319d842c688300: LogGCOp(19ac1f9a561748e8902d413f44dc75a7) complete. Timing: real 0.024s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:18:20.527604   788 maintenance_manager.cc:419] P c39cbdd68e1f4e5a9f319d842c688300: Scheduling FlushDeltaMemStoresOp(19ac1f9a561748e8902d413f44dc75a7): perf score=6.157687
I20260812 06:18:20.547290   667 maintenance_manager.cc:643] P c39cbdd68e1f4e5a9f319d842c688300: FlushDeltaMemStoresOp(19ac1f9a561748e8902d413f44dc75a7) complete. Timing: real 0.020s	user 0.002s	sys 0.016s Metrics: {"bytes_written":8328151,"delete_count":0,"lbm_write_time_us":8266,"lbm_writes_lt_1ms":206,"mutex_wait_us":174,"reinsert_count":0,"update_count":1015}
I20260812 06:18:20.547690   788 maintenance_manager.cc:419] P c39cbdd68e1f4e5a9f319d842c688300: Scheduling FlushDeltaMemStoresOp(19ac1f9a561748e8902d413f44dc75a7): perf score=2.188937
I20260812 06:18:20.565071   667 maintenance_manager.cc:643] P c39cbdd68e1f4e5a9f319d842c688300: FlushDeltaMemStoresOp(19ac1f9a561748e8902d413f44dc75a7) complete. Timing: real 0.017s	user 0.009s	sys 0.003s Metrics: {"bytes_written":3979583,"delete_count":0,"lbm_write_time_us":4914,"lbm_writes_lt_1ms":100,"reinsert_count":0,"update_count":485}
I20260812 06:18:20.565493   788 maintenance_manager.cc:419] P c39cbdd68e1f4e5a9f319d842c688300: Scheduling MajorDeltaCompactionOp(19ac1f9a561748e8902d413f44dc75a7): perf score=1.000000
I20260812 06:18:20.888865   667 maintenance_manager.cc:643] P c39cbdd68e1f4e5a9f319d842c688300: MajorDeltaCompactionOp(19ac1f9a561748e8902d413f44dc75a7) complete. Timing: real 0.323s	user 0.216s	sys 0.084s Metrics: {"cfile_cache_miss":1134,"cfile_cache_miss_bytes":49430385,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":650,"lbm_read_time_us":21325,"lbm_reads_lt_1ms":1166,"lbm_write_time_us":52115,"lbm_writes_lt_1ms":1143,"mutex_wait_us":49,"peak_mem_usage":137675332,"reinsert_count":0,"spinlock_wait_cycles":16000,"thread_start_us":299,"threads_started":6,"update_count":5500}
I20260812 06:18:20.889360   788 maintenance_manager.cc:419] P c39cbdd68e1f4e5a9f319d842c688300: Scheduling FlushDeltaMemStoresOp(19ac1f9a561748e8902d413f44dc75a7): perf score=26.001437
I20260812 06:18:20.968658   667 maintenance_manager.cc:643] P c39cbdd68e1f4e5a9f319d842c688300: FlushDeltaMemStoresOp(19ac1f9a561748e8902d413f44dc75a7) complete. Timing: real 0.079s	user 0.050s	sys 0.027s Metrics: {"bytes_written":28717139,"delete_count":0,"lbm_write_time_us":35237,"lbm_writes_lt_1ms":703,"reinsert_count":0,"spinlock_wait_cycles":1920,"update_count":3500}
I20260812 06:18:20.969244   788 maintenance_manager.cc:419] P c39cbdd68e1f4e5a9f319d842c688300: Scheduling UndoDeltaBlockGCOp(19ac1f9a561748e8902d413f44dc75a7): 462 bytes on disk
I20260812 06:18:20.969729   667 maintenance_manager.cc:643] P c39cbdd68e1f4e5a9f319d842c688300: UndoDeltaBlockGCOp(19ac1f9a561748e8902d413f44dc75a7) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":71,"lbm_reads_lt_1ms":4}
I20260812 06:18:20.970319   788 maintenance_manager.cc:419] P c39cbdd68e1f4e5a9f319d842c688300: Scheduling FlushDeltaMemStoresOp(19ac1f9a561748e8902d413f44dc75a7): perf score=2.188937
I20260812 06:18:21.004387   667 maintenance_manager.cc:643] P c39cbdd68e1f4e5a9f319d842c688300: FlushDeltaMemStoresOp(19ac1f9a561748e8902d413f44dc75a7) complete. Timing: real 0.034s	user 0.011s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4932,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:21.004920   788 maintenance_manager.cc:419] P c39cbdd68e1f4e5a9f319d842c688300: Scheduling FlushDeltaMemStoresOp(19ac1f9a561748e8902d413f44dc75a7): perf score=2.188937
I20260812 06:18:21.019718   667 maintenance_manager.cc:643] P c39cbdd68e1f4e5a9f319d842c688300: FlushDeltaMemStoresOp(19ac1f9a561748e8902d413f44dc75a7) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5432,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:21.020192   788 maintenance_manager.cc:419] P c39cbdd68e1f4e5a9f319d842c688300: Scheduling MajorDeltaCompactionOp(19ac1f9a561748e8902d413f44dc75a7): perf score=1.000000
I20260812 06:18:21.273334   667 maintenance_manager.cc:643] P c39cbdd68e1f4e5a9f319d842c688300: MajorDeltaCompactionOp(19ac1f9a561748e8902d413f44dc75a7) complete. Timing: real 0.253s	user 0.162s	sys 0.088s Metrics: {"cfile_cache_miss":933,"cfile_cache_miss_bytes":41225452,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":211,"lbm_read_time_us":19010,"lbm_reads_lt_1ms":965,"lbm_write_time_us":45587,"lbm_writes_lt_1ms":943,"mutex_wait_us":21,"peak_mem_usage":112822188,"reinsert_count":0,"spinlock_wait_cycles":17920,"update_count":4500}
I20260812 06:18:21.274060   788 maintenance_manager.cc:419] P c39cbdd68e1f4e5a9f319d842c688300: Scheduling FlushDeltaMemStoresOp(19ac1f9a561748e8902d413f44dc75a7): perf score=22.032687
I20260812 06:18:21.348567   667 maintenance_manager.cc:643] P c39cbdd68e1f4e5a9f319d842c688300: FlushDeltaMemStoresOp(19ac1f9a561748e8902d413f44dc75a7) complete. Timing: real 0.074s	user 0.034s	sys 0.038s Metrics: {"bytes_written":24614722,"delete_count":0,"lbm_write_time_us":32891,"lbm_writes_lt_1ms":603,"reinsert_count":0,"update_count":3000}
I20260812 06:18:21.349086   788 maintenance_manager.cc:419] P c39cbdd68e1f4e5a9f319d842c688300: Scheduling FlushDeltaMemStoresOp(19ac1f9a561748e8902d413f44dc75a7): perf score=2.188937
I20260812 06:18:21.369148   667 maintenance_manager.cc:643] P c39cbdd68e1f4e5a9f319d842c688300: FlushDeltaMemStoresOp(19ac1f9a561748e8902d413f44dc75a7) complete. Timing: real 0.020s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4246,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:21.369573   788 maintenance_manager.cc:419] P c39cbdd68e1f4e5a9f319d842c688300: Scheduling FlushDeltaMemStoresOp(19ac1f9a561748e8902d413f44dc75a7): perf score=2.188937
I20260812 06:18:21.383769   667 maintenance_manager.cc:643] P c39cbdd68e1f4e5a9f319d842c688300: FlushDeltaMemStoresOp(19ac1f9a561748e8902d413f44dc75a7) complete. Timing: real 0.014s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5580,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:21.384178   788 maintenance_manager.cc:419] P c39cbdd68e1f4e5a9f319d842c688300: Scheduling MajorDeltaCompactionOp(19ac1f9a561748e8902d413f44dc75a7): perf score=1.000000
I20260812 06:18:21.645900   667 maintenance_manager.cc:643] P c39cbdd68e1f4e5a9f319d842c688300: MajorDeltaCompactionOp(19ac1f9a561748e8902d413f44dc75a7) complete. Timing: real 0.262s	user 0.171s	sys 0.088s Metrics: {"cfile_cache_miss":833,"cfile_cache_miss_bytes":37123035,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":129,"lbm_read_time_us":18074,"lbm_reads_lt_1ms":873,"lbm_write_time_us":47472,"lbm_writes_lt_1ms":843,"mutex_wait_us":26,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":14208,"update_count":4000}
I20260812 06:18:21.646550   788 maintenance_manager.cc:419] P c39cbdd68e1f4e5a9f319d842c688300: Scheduling FlushDeltaMemStoresOp(19ac1f9a561748e8902d413f44dc75a7): perf score=19.056125
I20260812 06:18:21.715549   667 maintenance_manager.cc:643] P c39cbdd68e1f4e5a9f319d842c688300: FlushDeltaMemStoresOp(19ac1f9a561748e8902d413f44dc75a7) complete. Timing: real 0.069s	user 0.034s	sys 0.020s Metrics: {"bytes_written":20922553,"delete_count":0,"lbm_write_time_us":24830,"lbm_writes_lt_1ms":513,"reinsert_count":0,"update_count":2550}
I20260812 06:18:21.715999   788 maintenance_manager.cc:419] P c39cbdd68e1f4e5a9f319d842c688300: Scheduling FlushDeltaMemStoresOp(19ac1f9a561748e8902d413f44dc75a7): perf score=6.157687
I20260812 06:18:21.738780   667 maintenance_manager.cc:643] P c39cbdd68e1f4e5a9f319d842c688300: FlushDeltaMemStoresOp(19ac1f9a561748e8902d413f44dc75a7) complete. Timing: real 0.023s	user 0.017s	sys 0.004s Metrics: {"bytes_written":7794837,"delete_count":0,"lbm_write_time_us":9277,"lbm_writes_lt_1ms":193,"reinsert_count":0,"update_count":950}
I20260812 06:18:21.739274   788 maintenance_manager.cc:419] P c39cbdd68e1f4e5a9f319d842c688300: Scheduling MajorDeltaCompactionOp(19ac1f9a561748e8902d413f44dc75a7): perf score=1.000000
I20260812 06:18:21.935259   667 maintenance_manager.cc:643] P c39cbdd68e1f4e5a9f319d842c688300: MajorDeltaCompactionOp(19ac1f9a561748e8902d413f44dc75a7) complete. Timing: real 0.196s	user 0.152s	sys 0.032s Metrics: {"cfile_cache_miss":732,"cfile_cache_miss_bytes":33020507,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":869,"lbm_read_time_us":14767,"lbm_reads_lt_1ms":772,"lbm_write_time_us":38259,"lbm_writes_lt_1ms":743,"mutex_wait_us":305,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":14080,"update_count":3500}
I20260812 06:18:21.935856   788 maintenance_manager.cc:419] P c39cbdd68e1f4e5a9f319d842c688300: Scheduling FlushDeltaMemStoresOp(19ac1f9a561748e8902d413f44dc75a7): perf score=18.063937
I20260812 06:18:21.995711   667 maintenance_manager.cc:643] P c39cbdd68e1f4e5a9f319d842c688300: FlushDeltaMemStoresOp(19ac1f9a561748e8902d413f44dc75a7) complete. Timing: real 0.060s	user 0.025s	sys 0.032s Metrics: {"bytes_written":20512318,"delete_count":0,"lbm_write_time_us":25926,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:21.996338   788 maintenance_manager.cc:419] P c39cbdd68e1f4e5a9f319d842c688300: Scheduling FlushDeltaMemStoresOp(19ac1f9a561748e8902d413f44dc75a7): perf score=2.188937
I20260812 06:18:22.020874   667 maintenance_manager.cc:643] P c39cbdd68e1f4e5a9f319d842c688300: FlushDeltaMemStoresOp(19ac1f9a561748e8902d413f44dc75a7) complete. Timing: real 0.024s	user 0.005s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5439,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:22.021303   788 maintenance_manager.cc:419] P c39cbdd68e1f4e5a9f319d842c688300: Scheduling FlushDeltaMemStoresOp(19ac1f9a561748e8902d413f44dc75a7): perf score=2.188937
I20260812 06:18:22.031109   667 maintenance_manager.cc:643] P c39cbdd68e1f4e5a9f319d842c688300: FlushDeltaMemStoresOp(19ac1f9a561748e8902d413f44dc75a7) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3721,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:22.031517   788 maintenance_manager.cc:419] P c39cbdd68e1f4e5a9f319d842c688300: Scheduling FlushMRSOp(19ac1f9a561748e8902d413f44dc75a7): perf score=1.000000
I20260812 06:18:22.059937   667 maintenance_manager.cc:643] P c39cbdd68e1f4e5a9f319d842c688300: FlushMRSOp(19ac1f9a561748e8902d413f44dc75a7) complete. Timing: real 0.028s	user 0.022s	sys 0.004s Metrics: {"bytes_written":1357582,"cfile_init":1,"dirs.queue_time_us":63,"dirs.run_cpu_time_us":196,"dirs.run_wall_time_us":1330,"drs_written":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1729,"lbm_writes_lt_1ms":44,"peak_mem_usage":0,"rows_written":33}
I20260812 06:18:22.060639   788 maintenance_manager.cc:419] P c39cbdd68e1f4e5a9f319d842c688300: Scheduling LogGCOp(19ac1f9a561748e8902d413f44dc75a7): free 141791794 bytes of WAL
I20260812 06:18:22.060866   667 log_reader.cc:385] T 19ac1f9a561748e8902d413f44dc75a7: removed 14 log segments from log reader
I20260812 06:18:22.060918   667 log.cc:1079] T 19ac1f9a561748e8902d413f44dc75a7 P c39cbdd68e1f4e5a9f319d842c688300: Deleting log segment in path: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515492304271-32569-0/minicluster-data/ts-0-root/wals/19ac1f9a561748e8902d413f44dc75a7/wal-000000027 (ops 131-135)
I20260812 06:18:22.060957   667 log.cc:1079] T 19ac1f9a561748e8902d413f44dc75a7 P c39cbdd68e1f4e5a9f319d842c688300: Deleting log segment in path: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515492304271-32569-0/minicluster-data/ts-0-root/wals/19ac1f9a561748e8902d413f44dc75a7/wal-000000028 (ops 136-140)
I20260812 06:18:22.060981   667 log.cc:1079] T 19ac1f9a561748e8902d413f44dc75a7 P c39cbdd68e1f4e5a9f319d842c688300: Deleting log segment in path: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515492304271-32569-0/minicluster-data/ts-0-root/wals/19ac1f9a561748e8902d413f44dc75a7/wal-000000029 (ops 141-145)
I20260812 06:18:22.061014   667 log.cc:1079] T 19ac1f9a561748e8902d413f44dc75a7 P c39cbdd68e1f4e5a9f319d842c688300: Deleting log segment in path: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515492304271-32569-0/minicluster-data/ts-0-root/wals/19ac1f9a561748e8902d413f44dc75a7/wal-000000030 (ops 146-150)
I20260812 06:18:22.061045   667 log.cc:1079] T 19ac1f9a561748e8902d413f44dc75a7 P c39cbdd68e1f4e5a9f319d842c688300: Deleting log segment in path: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515492304271-32569-0/minicluster-data/ts-0-root/wals/19ac1f9a561748e8902d413f44dc75a7/wal-000000031 (ops 151-155)
I20260812 06:18:22.061077   667 log.cc:1079] T 19ac1f9a561748e8902d413f44dc75a7 P c39cbdd68e1f4e5a9f319d842c688300: Deleting log segment in path: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515492304271-32569-0/minicluster-data/ts-0-root/wals/19ac1f9a561748e8902d413f44dc75a7/wal-000000032 (ops 156-160)
I20260812 06:18:22.061107   667 log.cc:1079] T 19ac1f9a561748e8902d413f44dc75a7 P c39cbdd68e1f4e5a9f319d842c688300: Deleting log segment in path: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515492304271-32569-0/minicluster-data/ts-0-root/wals/19ac1f9a561748e8902d413f44dc75a7/wal-000000033 (ops 161-165)
I20260812 06:18:22.061138   667 log.cc:1079] T 19ac1f9a561748e8902d413f44dc75a7 P c39cbdd68e1f4e5a9f319d842c688300: Deleting log segment in path: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515492304271-32569-0/minicluster-data/ts-0-root/wals/19ac1f9a561748e8902d413f44dc75a7/wal-000000034 (ops 166-170)
I20260812 06:18:22.061168   667 log.cc:1079] T 19ac1f9a561748e8902d413f44dc75a7 P c39cbdd68e1f4e5a9f319d842c688300: Deleting log segment in path: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515492304271-32569-0/minicluster-data/ts-0-root/wals/19ac1f9a561748e8902d413f44dc75a7/wal-000000035 (ops 171-175)
I20260812 06:18:22.061200   667 log.cc:1079] T 19ac1f9a561748e8902d413f44dc75a7 P c39cbdd68e1f4e5a9f319d842c688300: Deleting log segment in path: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515492304271-32569-0/minicluster-data/ts-0-root/wals/19ac1f9a561748e8902d413f44dc75a7/wal-000000036 (ops 176-180)
I20260812 06:18:22.061237   667 log.cc:1079] T 19ac1f9a561748e8902d413f44dc75a7 P c39cbdd68e1f4e5a9f319d842c688300: Deleting log segment in path: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515492304271-32569-0/minicluster-data/ts-0-root/wals/19ac1f9a561748e8902d413f44dc75a7/wal-000000037 (ops 181-184)
I20260812 06:18:22.061269   667 log.cc:1079] T 19ac1f9a561748e8902d413f44dc75a7 P c39cbdd68e1f4e5a9f319d842c688300: Deleting log segment in path: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515492304271-32569-0/minicluster-data/ts-0-root/wals/19ac1f9a561748e8902d413f44dc75a7/wal-000000038 (ops 185-189)
I20260812 06:18:22.061299   667 log.cc:1079] T 19ac1f9a561748e8902d413f44dc75a7 P c39cbdd68e1f4e5a9f319d842c688300: Deleting log segment in path: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515492304271-32569-0/minicluster-data/ts-0-root/wals/19ac1f9a561748e8902d413f44dc75a7/wal-000000039 (ops 190-194)
I20260812 06:18:22.061329   667 log.cc:1079] T 19ac1f9a561748e8902d413f44dc75a7 P c39cbdd68e1f4e5a9f319d842c688300: Deleting log segment in path: /tmp/dist-test-taskHM9nYN/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515492304271-32569-0/minicluster-data/ts-0-root/wals/19ac1f9a561748e8902d413f44dc75a7/wal-000000040 (ops 195-199)
I20260812 06:18:22.088265   667 maintenance_manager.cc:643] P c39cbdd68e1f4e5a9f319d842c688300: LogGCOp(19ac1f9a561748e8902d413f44dc75a7) complete. Timing: real 0.027s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:18:22.088671   788 maintenance_manager.cc:419] P c39cbdd68e1f4e5a9f319d842c688300: Scheduling FlushDeltaMemStoresOp(19ac1f9a561748e8902d413f44dc75a7): perf score=3.181125
I20260812 06:18:22.108547 32569 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.509s	user 1.637s	sys 0.149s
I20260812 06:18:22.110409   667 maintenance_manager.cc:643] P c39cbdd68e1f4e5a9f319d842c688300: FlushDeltaMemStoresOp(19ac1f9a561748e8902d413f44dc75a7) complete. Timing: real 0.022s	user 0.019s	sys 0.000s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":7926,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:22.110970   788 maintenance_manager.cc:419] P c39cbdd68e1f4e5a9f319d842c688300: Scheduling FlushDeltaMemStoresOp(19ac1f9a561748e8902d413f44dc75a7): perf score=2.188937
I20260812 06:18:22.126606   667 maintenance_manager.cc:643] P c39cbdd68e1f4e5a9f319d842c688300: FlushDeltaMemStoresOp(19ac1f9a561748e8902d413f44dc75a7) complete. Timing: real 0.015s	user 0.011s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6424,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:22.127038   788 maintenance_manager.cc:419] P c39cbdd68e1f4e5a9f319d842c688300: Scheduling UndoDeltaBlockGCOp(19ac1f9a561748e8902d413f44dc75a7): 507 bytes on disk
I20260812 06:18:22.127444   667 maintenance_manager.cc:643] P c39cbdd68e1f4e5a9f319d842c688300: UndoDeltaBlockGCOp(19ac1f9a561748e8902d413f44dc75a7) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":51,"lbm_reads_lt_1ms":4}
I20260812 06:18:22.127928   788 maintenance_manager.cc:419] P c39cbdd68e1f4e5a9f319d842c688300: Scheduling MajorDeltaCompactionOp(19ac1f9a561748e8902d413f44dc75a7): perf score=1.000000
I20260812 06:18:22.189729 32569 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.081s	user 0.001s	sys 0.000s
I20260812 06:18:22.190241 32569 tablet_server.cc:179] TabletServer@127.31.206.65:0 shutting down...
I20260812 06:18:22.310066   667 maintenance_manager.cc:643] P c39cbdd68e1f4e5a9f319d842c688300: MajorDeltaCompactionOp(19ac1f9a561748e8902d413f44dc75a7) complete. Timing: real 0.182s	user 0.145s	sys 0.036s Metrics: {"cfile_cache_hit":348,"cfile_cache_hit_bytes":14118892,"cfile_cache_miss":587,"cfile_cache_miss_bytes":27106788,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":1090,"lbm_read_time_us":10616,"lbm_reads_lt_1ms":619,"lbm_write_time_us":39096,"lbm_writes_lt_1ms":943,"mutex_wait_us":63,"peak_mem_usage":112822188,"reinsert_count":0,"spinlock_wait_cycles":185472,"thread_start_us":76,"threads_started":1,"update_count":4500}
I20260812 06:18:22.310580 32569 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:22.310789 32569 tablet_replica.cc:333] T 19ac1f9a561748e8902d413f44dc75a7 P c39cbdd68e1f4e5a9f319d842c688300: stopping tablet replica
I20260812 06:18:22.310935 32569 raft_consensus.cc:2243] T 19ac1f9a561748e8902d413f44dc75a7 P c39cbdd68e1f4e5a9f319d842c688300 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:22.311091 32569 raft_consensus.cc:2272] T 19ac1f9a561748e8902d413f44dc75a7 P c39cbdd68e1f4e5a9f319d842c688300 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:22.325958 32569 tablet_server.cc:196] TabletServer@127.31.206.65:0 shutdown complete.
I20260812 06:18:22.396668 32569 master.cc:562] Master@127.31.206.126:40225 shutting down...
I20260812 06:18:22.399922 32569 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 28f2906f328f40818af3f2818653815e [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:22.400084 32569 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 28f2906f328f40818af3f2818653815e [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:22.400132 32569 tablet_replica.cc:333] T 00000000000000000000000000000000 P 28f2906f328f40818af3f2818653815e: stopping tablet replica
I20260812 06:18:22.412256 32569 master.cc:584] Master@127.31.206.126:40225 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5095 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10170 ms total)

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