[==========] 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:17:33.292572  7439 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.7.67.254:46335
I20260812 06:17:33.293529  7439 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:17:33.294061  7439 file_cache.cc:504] Constructed file cache file cache with capacity 419430
I20260812 06:17:33.300340  7439 server_base.cc:1061] running on GCE node
W20260812 06:17:33.300470  7451 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:17:33.300592  7447 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:17:33.300779  7445 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:17:33.301318  7439 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:33.301411  7439 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:17:33.301440  7439 hybrid_clock.cc:648] HybridClock initialized: now 1786515453301438 us; error 0 us; skew 500 ppm
I20260812 06:17:33.303198  7439 webserver.cc:533] Webserver started at http://127.7.67.254:40109/ using document root <none> and password file <none>
I20260812 06:17:33.303709  7439 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:33.303771  7439 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:33.303972  7439 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:33.305661  7439 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453282085-7439-0/minicluster-data/master-0-root/instance:
uuid: "dce11d4350af4411b4fd4b0a0d198147"
format_stamp: "Formatted at 2026-08-12 06:17:33 on dist-test-slave-k5rr"
I20260812 06:17:33.309033  7439 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.002s	sys 0.001s
I20260812 06:17:33.311000  7458 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:17:33.312007  7439 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:33.312114  7439 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453282085-7439-0/minicluster-data/master-0-root
uuid: "dce11d4350af4411b4fd4b0a0d198147"
format_stamp: "Formatted at 2026-08-12 06:17:33 on dist-test-slave-k5rr"
I20260812 06:17:33.312208  7439 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453282085-7439-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453282085-7439-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453282085-7439-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:17:33.338304  7439 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:33.338979  7439 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:17:33.339143  7439 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:33.346701  7552 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.7.67.254:46335 every 8 connection(s)
I20260812 06:17:33.346704  7439 rpc_server.cc:307] RPC server started. Bound to: 127.7.67.254:46335
I20260812 06:17:33.348959  7553 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:17:33.354275  7553 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P dce11d4350af4411b4fd4b0a0d198147: Bootstrap starting.
I20260812 06:17:33.356822  7553 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P dce11d4350af4411b4fd4b0a0d198147: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:33.357969  7553 log.cc:826] T 00000000000000000000000000000000 P dce11d4350af4411b4fd4b0a0d198147: Log is configured to *not* fsync() on all Append() calls
I20260812 06:17:33.359683  7553 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P dce11d4350af4411b4fd4b0a0d198147: No bootstrap required, opened a new log
I20260812 06:17:33.362366  7553 raft_consensus.cc:359] T 00000000000000000000000000000000 P dce11d4350af4411b4fd4b0a0d198147 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "dce11d4350af4411b4fd4b0a0d198147" member_type: VOTER }
I20260812 06:17:33.362532  7553 raft_consensus.cc:385] T 00000000000000000000000000000000 P dce11d4350af4411b4fd4b0a0d198147 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:33.362572  7553 raft_consensus.cc:740] T 00000000000000000000000000000000 P dce11d4350af4411b4fd4b0a0d198147 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: dce11d4350af4411b4fd4b0a0d198147, State: Initialized, Role: FOLLOWER
I20260812 06:17:33.363137  7553 consensus_queue.cc:260] T 00000000000000000000000000000000 P dce11d4350af4411b4fd4b0a0d198147 [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: "dce11d4350af4411b4fd4b0a0d198147" member_type: VOTER }
I20260812 06:17:33.363279  7553 raft_consensus.cc:399] T 00000000000000000000000000000000 P dce11d4350af4411b4fd4b0a0d198147 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:33.363325  7553 raft_consensus.cc:493] T 00000000000000000000000000000000 P dce11d4350af4411b4fd4b0a0d198147 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:33.363426  7553 raft_consensus.cc:3060] T 00000000000000000000000000000000 P dce11d4350af4411b4fd4b0a0d198147 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:33.364109  7553 raft_consensus.cc:515] T 00000000000000000000000000000000 P dce11d4350af4411b4fd4b0a0d198147 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "dce11d4350af4411b4fd4b0a0d198147" member_type: VOTER }
I20260812 06:17:33.364491  7553 leader_election.cc:304] T 00000000000000000000000000000000 P dce11d4350af4411b4fd4b0a0d198147 [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: dce11d4350af4411b4fd4b0a0d198147; no voters: 
I20260812 06:17:33.364744  7553 leader_election.cc:290] T 00000000000000000000000000000000 P dce11d4350af4411b4fd4b0a0d198147 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:33.364880  7556 raft_consensus.cc:2804] T 00000000000000000000000000000000 P dce11d4350af4411b4fd4b0a0d198147 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:33.365171  7556 raft_consensus.cc:697] T 00000000000000000000000000000000 P dce11d4350af4411b4fd4b0a0d198147 [term 1 LEADER]: Becoming Leader. State: Replica: dce11d4350af4411b4fd4b0a0d198147, State: Running, Role: LEADER
I20260812 06:17:33.365581  7556 consensus_queue.cc:237] T 00000000000000000000000000000000 P dce11d4350af4411b4fd4b0a0d198147 [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: "dce11d4350af4411b4fd4b0a0d198147" member_type: VOTER }
I20260812 06:17:33.365658  7553 sys_catalog.cc:565] T 00000000000000000000000000000000 P dce11d4350af4411b4fd4b0a0d198147 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:33.367440  7557 sys_catalog.cc:455] T 00000000000000000000000000000000 P dce11d4350af4411b4fd4b0a0d198147 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "dce11d4350af4411b4fd4b0a0d198147" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "dce11d4350af4411b4fd4b0a0d198147" member_type: VOTER } }
I20260812 06:17:33.367553  7557 sys_catalog.cc:458] T 00000000000000000000000000000000 P dce11d4350af4411b4fd4b0a0d198147 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:33.367749  7439 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:33.367832  7559 sys_catalog.cc:455] T 00000000000000000000000000000000 P dce11d4350af4411b4fd4b0a0d198147 [sys.catalog]: SysCatalogTable state changed. Reason: New leader dce11d4350af4411b4fd4b0a0d198147. Latest consensus state: current_term: 1 leader_uuid: "dce11d4350af4411b4fd4b0a0d198147" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "dce11d4350af4411b4fd4b0a0d198147" member_type: VOTER } }
I20260812 06:17:33.367890  7582 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:33.367913  7559 sys_catalog.cc:458] T 00000000000000000000000000000000 P dce11d4350af4411b4fd4b0a0d198147 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:33.370088  7582 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:33.374399  7582 catalog_manager.cc:1383] Generated new cluster ID: 731a803047124c66b5312709131c307b
I20260812 06:17:33.374465  7582 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:33.384243  7582 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:33.385044  7582 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:33.397145  7582 catalog_manager.cc:6092] T 00000000000000000000000000000000 P dce11d4350af4411b4fd4b0a0d198147: Generated new TSK 0
I20260812 06:17:33.397764  7582 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:33.400359  7439 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:33.402863  7591 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:17:33.402969  7595 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:17:33.402962  7593 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:17:33.403506  7439 server_base.cc:1061] running on GCE node
I20260812 06:17:33.403671  7439 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:33.403719  7439 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:17:33.403754  7439 hybrid_clock.cc:648] HybridClock initialized: now 1786515453403753 us; error 0 us; skew 500 ppm
I20260812 06:17:33.404649  7439 webserver.cc:533] Webserver started at http://127.7.67.193:35061/ using document root <none> and password file <none>
I20260812 06:17:33.404824  7439 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:33.404883  7439 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:33.404964  7439 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:33.405385  7439 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453282085-7439-0/minicluster-data/ts-0-root/instance:
uuid: "6f8dd1a7e20246ec8c323f9c45330ba1"
format_stamp: "Formatted at 2026-08-12 06:17:33 on dist-test-slave-k5rr"
I20260812 06:17:33.407157  7439 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:33.408115  7601 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:17:33.408384  7439 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:33.408452  7439 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453282085-7439-0/minicluster-data/ts-0-root
uuid: "6f8dd1a7e20246ec8c323f9c45330ba1"
format_stamp: "Formatted at 2026-08-12 06:17:33 on dist-test-slave-k5rr"
I20260812 06:17:33.408524  7439 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453282085-7439-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453282085-7439-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453282085-7439-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:17:33.419503  7439 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:33.419894  7439 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:33.420356  7439 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:33.421252  7439 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:33.421303  7439 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:33.421347  7439 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:33.421376  7439 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:33.427453  7439 rpc_server.cc:307] RPC server started. Bound to: 127.7.67.193:41139
I20260812 06:17:33.427520  7709 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.7.67.193:41139 every 8 connection(s)
I20260812 06:17:33.440057  7710 heartbeater.cc:344] Connected to a master server at 127.7.67.254:46335
I20260812 06:17:33.440315  7710 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:33.440842  7710 heartbeater.cc:507] Master 127.7.67.254:46335 requested a full tablet report, sending...
I20260812 06:17:33.442458  7482 ts_manager.cc:194] Registered new tserver with Master: 6f8dd1a7e20246ec8c323f9c45330ba1 (127.7.67.193:41139)
I20260812 06:17:33.442569  7439 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.014539914s
I20260812 06:17:33.444005  7482 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:34044
I20260812 06:17:33.451606  7482 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:34054:
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:17:33.465629  7642 tablet_service.cc:1511] Processing CreateTablet for tablet c1966adf4d8a4a1db4a3861ad448eabd (DEFAULT_TABLE table=heavy-update-compaction-test [id=50a72d2cd6004cf4bf4f5724cfece58d]), partition=
I20260812 06:17:33.466084  7642 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet c1966adf4d8a4a1db4a3861ad448eabd. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:33.468397  7731 tablet_bootstrap.cc:492] T c1966adf4d8a4a1db4a3861ad448eabd P 6f8dd1a7e20246ec8c323f9c45330ba1: Bootstrap starting.
I20260812 06:17:33.469619  7731 tablet_bootstrap.cc:654] T c1966adf4d8a4a1db4a3861ad448eabd P 6f8dd1a7e20246ec8c323f9c45330ba1: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:33.470659  7731 tablet_bootstrap.cc:492] T c1966adf4d8a4a1db4a3861ad448eabd P 6f8dd1a7e20246ec8c323f9c45330ba1: No bootstrap required, opened a new log
I20260812 06:17:33.470743  7731 ts_tablet_manager.cc:1403] T c1966adf4d8a4a1db4a3861ad448eabd P 6f8dd1a7e20246ec8c323f9c45330ba1: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:33.471123  7731 raft_consensus.cc:359] T c1966adf4d8a4a1db4a3861ad448eabd P 6f8dd1a7e20246ec8c323f9c45330ba1 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6f8dd1a7e20246ec8c323f9c45330ba1" member_type: VOTER last_known_addr { host: "127.7.67.193" port: 41139 } }
I20260812 06:17:33.471217  7731 raft_consensus.cc:385] T c1966adf4d8a4a1db4a3861ad448eabd P 6f8dd1a7e20246ec8c323f9c45330ba1 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:33.471239  7731 raft_consensus.cc:740] T c1966adf4d8a4a1db4a3861ad448eabd P 6f8dd1a7e20246ec8c323f9c45330ba1 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 6f8dd1a7e20246ec8c323f9c45330ba1, State: Initialized, Role: FOLLOWER
I20260812 06:17:33.471346  7731 consensus_queue.cc:260] T c1966adf4d8a4a1db4a3861ad448eabd P 6f8dd1a7e20246ec8c323f9c45330ba1 [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: "6f8dd1a7e20246ec8c323f9c45330ba1" member_type: VOTER last_known_addr { host: "127.7.67.193" port: 41139 } }
I20260812 06:17:33.471412  7731 raft_consensus.cc:399] T c1966adf4d8a4a1db4a3861ad448eabd P 6f8dd1a7e20246ec8c323f9c45330ba1 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:33.471446  7731 raft_consensus.cc:493] T c1966adf4d8a4a1db4a3861ad448eabd P 6f8dd1a7e20246ec8c323f9c45330ba1 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:33.471503  7731 raft_consensus.cc:3060] T c1966adf4d8a4a1db4a3861ad448eabd P 6f8dd1a7e20246ec8c323f9c45330ba1 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:33.472195  7731 raft_consensus.cc:515] T c1966adf4d8a4a1db4a3861ad448eabd P 6f8dd1a7e20246ec8c323f9c45330ba1 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6f8dd1a7e20246ec8c323f9c45330ba1" member_type: VOTER last_known_addr { host: "127.7.67.193" port: 41139 } }
I20260812 06:17:33.472337  7731 leader_election.cc:304] T c1966adf4d8a4a1db4a3861ad448eabd P 6f8dd1a7e20246ec8c323f9c45330ba1 [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: 6f8dd1a7e20246ec8c323f9c45330ba1; no voters: 
I20260812 06:17:33.472515  7731 leader_election.cc:290] T c1966adf4d8a4a1db4a3861ad448eabd P 6f8dd1a7e20246ec8c323f9c45330ba1 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:33.472635  7733 raft_consensus.cc:2804] T c1966adf4d8a4a1db4a3861ad448eabd P 6f8dd1a7e20246ec8c323f9c45330ba1 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:33.472832  7731 ts_tablet_manager.cc:1434] T c1966adf4d8a4a1db4a3861ad448eabd P 6f8dd1a7e20246ec8c323f9c45330ba1: Time spent starting tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:33.473052  7733 raft_consensus.cc:697] T c1966adf4d8a4a1db4a3861ad448eabd P 6f8dd1a7e20246ec8c323f9c45330ba1 [term 1 LEADER]: Becoming Leader. State: Replica: 6f8dd1a7e20246ec8c323f9c45330ba1, State: Running, Role: LEADER
I20260812 06:17:33.473220  7733 consensus_queue.cc:237] T c1966adf4d8a4a1db4a3861ad448eabd P 6f8dd1a7e20246ec8c323f9c45330ba1 [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: "6f8dd1a7e20246ec8c323f9c45330ba1" member_type: VOTER last_known_addr { host: "127.7.67.193" port: 41139 } }
I20260812 06:17:33.473747  7710 heartbeater.cc:499] Master 127.7.67.254:46335 was elected leader, sending a full tablet report...
I20260812 06:17:33.476136  7482 catalog_manager.cc:5719] T c1966adf4d8a4a1db4a3861ad448eabd P 6f8dd1a7e20246ec8c323f9c45330ba1 reported cstate change: term changed from 0 to 1, leader changed from <none> to 6f8dd1a7e20246ec8c323f9c45330ba1 (127.7.67.193). New cstate: current_term: 1 leader_uuid: "6f8dd1a7e20246ec8c323f9c45330ba1" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6f8dd1a7e20246ec8c323f9c45330ba1" member_type: VOTER last_known_addr { host: "127.7.67.193" port: 41139 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:33.545149  7439 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.059s	user 0.020s	sys 0.012s
I20260812 06:17:33.678475  7712 maintenance_manager.cc:419] P 6f8dd1a7e20246ec8c323f9c45330ba1: Scheduling FlushMRSOp(c1966adf4d8a4a1db4a3861ad448eabd): perf score=19.054940
I20260812 06:17:33.877907  7609 maintenance_manager.cc:643] P 6f8dd1a7e20246ec8c323f9c45330ba1: FlushMRSOp(c1966adf4d8a4a1db4a3861ad448eabd) complete. Timing: real 0.199s	user 0.139s	sys 0.048s Metrics: {"bytes_written":14768932,"cfile_init":1,"compiler_manager_pool.queue_time_us":204,"delete_count":0,"dirs.queue_time_us":76,"dirs.run_cpu_time_us":289,"dirs.run_wall_time_us":991,"drs_written":1,"lbm_read_time_us":73,"lbm_reads_lt_1ms":4,"lbm_write_time_us":44730,"lbm_writes_lt_1ms":817,"mutex_wait_us":1687,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":121600,"thread_start_us":115,"threads_started":1,"update_count":1800}
I20260812 06:17:33.879251  7712 maintenance_manager.cc:419] P 6f8dd1a7e20246ec8c323f9c45330ba1: Scheduling LogGCOp(c1966adf4d8a4a1db4a3861ad448eabd): free 20743880 bytes of WAL
I20260812 06:17:33.879590  7609 log_reader.cc:385] T c1966adf4d8a4a1db4a3861ad448eabd: removed 2 log segments from log reader
I20260812 06:17:33.879668  7609 log.cc:1079] T c1966adf4d8a4a1db4a3861ad448eabd P 6f8dd1a7e20246ec8c323f9c45330ba1: Deleting log segment in path: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453282085-7439-0/minicluster-data/ts-0-root/wals/c1966adf4d8a4a1db4a3861ad448eabd/wal-000000001 (ops 1-6)
I20260812 06:17:33.879789  7609 log.cc:1079] T c1966adf4d8a4a1db4a3861ad448eabd P 6f8dd1a7e20246ec8c323f9c45330ba1: Deleting log segment in path: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453282085-7439-0/minicluster-data/ts-0-root/wals/c1966adf4d8a4a1db4a3861ad448eabd/wal-000000002 (ops 7-11)
I20260812 06:17:33.884768  7609 maintenance_manager.cc:643] P 6f8dd1a7e20246ec8c323f9c45330ba1: LogGCOp(c1966adf4d8a4a1db4a3861ad448eabd) complete. Timing: real 0.005s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:17:33.885159  7712 maintenance_manager.cc:419] P 6f8dd1a7e20246ec8c323f9c45330ba1: Scheduling UndoDeltaBlockGCOp(c1966adf4d8a4a1db4a3861ad448eabd): 16411393 bytes on disk
I20260812 06:17:33.885787  7609 maintenance_manager.cc:643] P 6f8dd1a7e20246ec8c323f9c45330ba1: UndoDeltaBlockGCOp(c1966adf4d8a4a1db4a3861ad448eabd) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":73,"lbm_reads_lt_1ms":4}
I20260812 06:17:33.886196  7712 maintenance_manager.cc:419] P 6f8dd1a7e20246ec8c323f9c45330ba1: Scheduling FlushDeltaMemStoresOp(c1966adf4d8a4a1db4a3861ad448eabd): perf score=4.173312
I20260812 06:17:33.905181  7609 maintenance_manager.cc:643] P 6f8dd1a7e20246ec8c323f9c45330ba1: FlushDeltaMemStoresOp(c1966adf4d8a4a1db4a3861ad448eabd) complete. Timing: real 0.019s	user 0.016s	sys 0.001s Metrics: {"bytes_written":5743636,"delete_count":0,"lbm_write_time_us":6828,"lbm_writes_lt_1ms":143,"reinsert_count":0,"update_count":700}
I20260812 06:17:33.905669  7712 maintenance_manager.cc:419] P 6f8dd1a7e20246ec8c323f9c45330ba1: Scheduling MajorDeltaCompactionOp(c1966adf4d8a4a1db4a3861ad448eabd): perf score=1.000000
I20260812 06:17:34.066051  7609 maintenance_manager.cc:643] P 6f8dd1a7e20246ec8c323f9c45330ba1: MajorDeltaCompactionOp(c1966adf4d8a4a1db4a3861ad448eabd) complete. Timing: real 0.160s	user 0.124s	sys 0.036s 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":898,"lbm_read_time_us":10675,"lbm_reads_lt_1ms":564,"lbm_write_time_us":24376,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8576,"thread_start_us":337,"threads_started":5,"update_count":2500}
I20260812 06:17:34.066633  7712 maintenance_manager.cc:419] P 6f8dd1a7e20246ec8c323f9c45330ba1: Scheduling FlushDeltaMemStoresOp(c1966adf4d8a4a1db4a3861ad448eabd): perf score=11.118625
I20260812 06:17:34.102715  7609 maintenance_manager.cc:643] P 6f8dd1a7e20246ec8c323f9c45330ba1: FlushDeltaMemStoresOp(c1966adf4d8a4a1db4a3861ad448eabd) complete. Timing: real 0.036s	user 0.014s	sys 0.020s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15080,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:34.103288  7712 maintenance_manager.cc:419] P 6f8dd1a7e20246ec8c323f9c45330ba1: Scheduling FlushDeltaMemStoresOp(c1966adf4d8a4a1db4a3861ad448eabd): perf score=2.188937
I20260812 06:17:34.116539  7609 maintenance_manager.cc:643] P 6f8dd1a7e20246ec8c323f9c45330ba1: FlushDeltaMemStoresOp(c1966adf4d8a4a1db4a3861ad448eabd) complete. Timing: real 0.013s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4930,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:34.116990  7712 maintenance_manager.cc:419] P 6f8dd1a7e20246ec8c323f9c45330ba1: Scheduling MajorDeltaCompactionOp(c1966adf4d8a4a1db4a3861ad448eabd): perf score=1.000000
I20260812 06:17:34.234345  7609 maintenance_manager.cc:643] P 6f8dd1a7e20246ec8c323f9c45330ba1: MajorDeltaCompactionOp(c1966adf4d8a4a1db4a3861ad448eabd) complete. Timing: real 0.117s	user 0.086s	sys 0.031s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":257,"lbm_read_time_us":7077,"lbm_reads_lt_1ms":464,"lbm_write_time_us":22187,"lbm_writes_lt_1ms":443,"mutex_wait_us":29,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:17:34.237460  7712 maintenance_manager.cc:419] P 6f8dd1a7e20246ec8c323f9c45330ba1: Scheduling FlushDeltaMemStoresOp(c1966adf4d8a4a1db4a3861ad448eabd): perf score=11.118625
I20260812 06:17:34.273806  7609 maintenance_manager.cc:643] P 6f8dd1a7e20246ec8c323f9c45330ba1: FlushDeltaMemStoresOp(c1966adf4d8a4a1db4a3861ad448eabd) complete. Timing: real 0.036s	user 0.022s	sys 0.014s Metrics: {"bytes_written":12553635,"delete_count":0,"lbm_write_time_us":15647,"lbm_writes_lt_1ms":309,"reinsert_count":0,"update_count":1530}
I20260812 06:17:34.274267  7712 maintenance_manager.cc:419] P 6f8dd1a7e20246ec8c323f9c45330ba1: Scheduling FlushDeltaMemStoresOp(c1966adf4d8a4a1db4a3861ad448eabd): perf score=2.188937
I20260812 06:17:34.285126  7609 maintenance_manager.cc:643] P 6f8dd1a7e20246ec8c323f9c45330ba1: FlushDeltaMemStoresOp(c1966adf4d8a4a1db4a3861ad448eabd) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":3856509,"delete_count":0,"lbm_write_time_us":3960,"lbm_writes_lt_1ms":97,"reinsert_count":0,"update_count":470}
I20260812 06:17:34.285604  7712 maintenance_manager.cc:419] P 6f8dd1a7e20246ec8c323f9c45330ba1: Scheduling MajorDeltaCompactionOp(c1966adf4d8a4a1db4a3861ad448eabd): perf score=1.000000
I20260812 06:17:34.404569  7609 maintenance_manager.cc:643] P 6f8dd1a7e20246ec8c323f9c45330ba1: MajorDeltaCompactionOp(c1966adf4d8a4a1db4a3861ad448eabd) complete. Timing: real 0.119s	user 0.101s	sys 0.017s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":715,"lbm_read_time_us":7252,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24144,"lbm_writes_lt_1ms":443,"mutex_wait_us":357,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":50176,"update_count":2000}
I20260812 06:17:34.405532  7712 maintenance_manager.cc:419] P 6f8dd1a7e20246ec8c323f9c45330ba1: Scheduling FlushDeltaMemStoresOp(c1966adf4d8a4a1db4a3861ad448eabd): perf score=10.126437
I20260812 06:17:34.439986  7609 maintenance_manager.cc:643] P 6f8dd1a7e20246ec8c323f9c45330ba1: FlushDeltaMemStoresOp(c1966adf4d8a4a1db4a3861ad448eabd) complete. Timing: real 0.034s	user 0.028s	sys 0.001s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13606,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:34.440518  7712 maintenance_manager.cc:419] P 6f8dd1a7e20246ec8c323f9c45330ba1: Scheduling FlushDeltaMemStoresOp(c1966adf4d8a4a1db4a3861ad448eabd): perf score=2.188937
I20260812 06:17:34.450484  7609 maintenance_manager.cc:643] P 6f8dd1a7e20246ec8c323f9c45330ba1: FlushDeltaMemStoresOp(c1966adf4d8a4a1db4a3861ad448eabd) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3738,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:34.451025  7712 maintenance_manager.cc:419] P 6f8dd1a7e20246ec8c323f9c45330ba1: Scheduling MajorDeltaCompactionOp(c1966adf4d8a4a1db4a3861ad448eabd): perf score=1.000000
I20260812 06:17:34.579245  7609 maintenance_manager.cc:643] P 6f8dd1a7e20246ec8c323f9c45330ba1: MajorDeltaCompactionOp(c1966adf4d8a4a1db4a3861ad448eabd) complete. Timing: real 0.128s	user 0.097s	sys 0.027s 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":897,"lbm_read_time_us":8053,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26836,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":442,"mutex_wait_us":42,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2000}
I20260812 06:17:34.579833  7712 maintenance_manager.cc:419] P 6f8dd1a7e20246ec8c323f9c45330ba1: Scheduling FlushDeltaMemStoresOp(c1966adf4d8a4a1db4a3861ad448eabd): perf score=10.126437
I20260812 06:17:34.629328  7609 maintenance_manager.cc:643] P 6f8dd1a7e20246ec8c323f9c45330ba1: FlushDeltaMemStoresOp(c1966adf4d8a4a1db4a3861ad448eabd) complete. Timing: real 0.049s	user 0.034s	sys 0.011s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":17752,"lbm_writes_lt_1ms":303,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":1500}
I20260812 06:17:34.629854  7712 maintenance_manager.cc:419] P 6f8dd1a7e20246ec8c323f9c45330ba1: Scheduling FlushDeltaMemStoresOp(c1966adf4d8a4a1db4a3861ad448eabd): perf score=2.188937
I20260812 06:17:34.639961  7609 maintenance_manager.cc:643] P 6f8dd1a7e20246ec8c323f9c45330ba1: FlushDeltaMemStoresOp(c1966adf4d8a4a1db4a3861ad448eabd) complete. Timing: real 0.010s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3883,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:34.640365  7712 maintenance_manager.cc:419] P 6f8dd1a7e20246ec8c323f9c45330ba1: Scheduling MajorDeltaCompactionOp(c1966adf4d8a4a1db4a3861ad448eabd): perf score=1.000000
I20260812 06:17:34.779284  7609 maintenance_manager.cc:643] P 6f8dd1a7e20246ec8c323f9c45330ba1: MajorDeltaCompactionOp(c1966adf4d8a4a1db4a3861ad448eabd) complete. Timing: real 0.139s	user 0.123s	sys 0.016s 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":305,"lbm_read_time_us":10155,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23442,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2816,"update_count":2000}
I20260812 06:17:34.779757  7712 maintenance_manager.cc:419] P 6f8dd1a7e20246ec8c323f9c45330ba1: Scheduling FlushDeltaMemStoresOp(c1966adf4d8a4a1db4a3861ad448eabd): perf score=10.126437
I20260812 06:17:34.828333  7609 maintenance_manager.cc:643] P 6f8dd1a7e20246ec8c323f9c45330ba1: FlushDeltaMemStoresOp(c1966adf4d8a4a1db4a3861ad448eabd) complete. Timing: real 0.048s	user 0.015s	sys 0.028s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":19407,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:17:34.828770  7712 maintenance_manager.cc:419] P 6f8dd1a7e20246ec8c323f9c45330ba1: Scheduling FlushDeltaMemStoresOp(c1966adf4d8a4a1db4a3861ad448eabd): perf score=2.188937
I20260812 06:17:34.838714  7609 maintenance_manager.cc:643] P 6f8dd1a7e20246ec8c323f9c45330ba1: FlushDeltaMemStoresOp(c1966adf4d8a4a1db4a3861ad448eabd) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3644,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:34.839226  7712 maintenance_manager.cc:419] P 6f8dd1a7e20246ec8c323f9c45330ba1: Scheduling MajorDeltaCompactionOp(c1966adf4d8a4a1db4a3861ad448eabd): perf score=1.000000
I20260812 06:17:34.954902  7609 maintenance_manager.cc:643] P 6f8dd1a7e20246ec8c323f9c45330ba1: MajorDeltaCompactionOp(c1966adf4d8a4a1db4a3861ad448eabd) complete. Timing: real 0.116s	user 0.091s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":526,"lbm_read_time_us":8185,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21835,"lbm_writes_lt_1ms":443,"mutex_wait_us":265,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3840,"update_count":2000}
I20260812 06:17:34.955381  7712 maintenance_manager.cc:419] P 6f8dd1a7e20246ec8c323f9c45330ba1: Scheduling FlushDeltaMemStoresOp(c1966adf4d8a4a1db4a3861ad448eabd): perf score=10.126437
I20260812 06:17:34.992467  7609 maintenance_manager.cc:643] P 6f8dd1a7e20246ec8c323f9c45330ba1: FlushDeltaMemStoresOp(c1966adf4d8a4a1db4a3861ad448eabd) complete. Timing: real 0.037s	user 0.009s	sys 0.024s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17059,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:17:34.992956  7712 maintenance_manager.cc:419] P 6f8dd1a7e20246ec8c323f9c45330ba1: Scheduling FlushDeltaMemStoresOp(c1966adf4d8a4a1db4a3861ad448eabd): perf score=2.188937
I20260812 06:17:35.002873  7609 maintenance_manager.cc:643] P 6f8dd1a7e20246ec8c323f9c45330ba1: FlushDeltaMemStoresOp(c1966adf4d8a4a1db4a3861ad448eabd) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3684,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:35.003377  7712 maintenance_manager.cc:419] P 6f8dd1a7e20246ec8c323f9c45330ba1: Scheduling FlushMRSOp(c1966adf4d8a4a1db4a3861ad448eabd): perf score=1.000000
I20260812 06:17:35.034221  7609 maintenance_manager.cc:643] P 6f8dd1a7e20246ec8c323f9c45330ba1: FlushMRSOp(c1966adf4d8a4a1db4a3861ad448eabd) complete. Timing: real 0.031s	user 0.025s	sys 0.004s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":50,"dirs.run_cpu_time_us":251,"dirs.run_wall_time_us":1197,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1611,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:17:35.035046  7712 maintenance_manager.cc:419] P 6f8dd1a7e20246ec8c323f9c45330ba1: Scheduling LogGCOp(c1966adf4d8a4a1db4a3861ad448eabd): free 112239277 bytes of WAL
I20260812 06:17:35.035261  7609 log_reader.cc:385] T c1966adf4d8a4a1db4a3861ad448eabd: removed 11 log segments from log reader
I20260812 06:17:35.035307  7609 log.cc:1079] T c1966adf4d8a4a1db4a3861ad448eabd P 6f8dd1a7e20246ec8c323f9c45330ba1: Deleting log segment in path: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453282085-7439-0/minicluster-data/ts-0-root/wals/c1966adf4d8a4a1db4a3861ad448eabd/wal-000000003 (ops 12-16)
I20260812 06:17:35.035337  7609 log.cc:1079] T c1966adf4d8a4a1db4a3861ad448eabd P 6f8dd1a7e20246ec8c323f9c45330ba1: Deleting log segment in path: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453282085-7439-0/minicluster-data/ts-0-root/wals/c1966adf4d8a4a1db4a3861ad448eabd/wal-000000004 (ops 17-21)
I20260812 06:17:35.035367  7609 log.cc:1079] T c1966adf4d8a4a1db4a3861ad448eabd P 6f8dd1a7e20246ec8c323f9c45330ba1: Deleting log segment in path: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453282085-7439-0/minicluster-data/ts-0-root/wals/c1966adf4d8a4a1db4a3861ad448eabd/wal-000000005 (ops 22-26)
I20260812 06:17:35.035398  7609 log.cc:1079] T c1966adf4d8a4a1db4a3861ad448eabd P 6f8dd1a7e20246ec8c323f9c45330ba1: Deleting log segment in path: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453282085-7439-0/minicluster-data/ts-0-root/wals/c1966adf4d8a4a1db4a3861ad448eabd/wal-000000006 (ops 27-31)
I20260812 06:17:35.035430  7609 log.cc:1079] T c1966adf4d8a4a1db4a3861ad448eabd P 6f8dd1a7e20246ec8c323f9c45330ba1: Deleting log segment in path: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453282085-7439-0/minicluster-data/ts-0-root/wals/c1966adf4d8a4a1db4a3861ad448eabd/wal-000000007 (ops 32-36)
I20260812 06:17:35.035462  7609 log.cc:1079] T c1966adf4d8a4a1db4a3861ad448eabd P 6f8dd1a7e20246ec8c323f9c45330ba1: Deleting log segment in path: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453282085-7439-0/minicluster-data/ts-0-root/wals/c1966adf4d8a4a1db4a3861ad448eabd/wal-000000008 (ops 37-41)
I20260812 06:17:35.035494  7609 log.cc:1079] T c1966adf4d8a4a1db4a3861ad448eabd P 6f8dd1a7e20246ec8c323f9c45330ba1: Deleting log segment in path: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453282085-7439-0/minicluster-data/ts-0-root/wals/c1966adf4d8a4a1db4a3861ad448eabd/wal-000000009 (ops 42-46)
I20260812 06:17:35.035524  7609 log.cc:1079] T c1966adf4d8a4a1db4a3861ad448eabd P 6f8dd1a7e20246ec8c323f9c45330ba1: Deleting log segment in path: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453282085-7439-0/minicluster-data/ts-0-root/wals/c1966adf4d8a4a1db4a3861ad448eabd/wal-000000010 (ops 47-50)
I20260812 06:17:35.035557  7609 log.cc:1079] T c1966adf4d8a4a1db4a3861ad448eabd P 6f8dd1a7e20246ec8c323f9c45330ba1: Deleting log segment in path: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453282085-7439-0/minicluster-data/ts-0-root/wals/c1966adf4d8a4a1db4a3861ad448eabd/wal-000000011 (ops 51-55)
I20260812 06:17:35.035586  7609 log.cc:1079] T c1966adf4d8a4a1db4a3861ad448eabd P 6f8dd1a7e20246ec8c323f9c45330ba1: Deleting log segment in path: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453282085-7439-0/minicluster-data/ts-0-root/wals/c1966adf4d8a4a1db4a3861ad448eabd/wal-000000012 (ops 56-60)
I20260812 06:17:35.035616  7609 log.cc:1079] T c1966adf4d8a4a1db4a3861ad448eabd P 6f8dd1a7e20246ec8c323f9c45330ba1: Deleting log segment in path: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453282085-7439-0/minicluster-data/ts-0-root/wals/c1966adf4d8a4a1db4a3861ad448eabd/wal-000000013 (ops 61-65)
I20260812 06:17:35.056740  7609 maintenance_manager.cc:643] P 6f8dd1a7e20246ec8c323f9c45330ba1: LogGCOp(c1966adf4d8a4a1db4a3861ad448eabd) complete. Timing: real 0.022s	user 0.000s	sys 0.018s Metrics: {}
I20260812 06:17:35.057224  7712 maintenance_manager.cc:419] P 6f8dd1a7e20246ec8c323f9c45330ba1: Scheduling FlushDeltaMemStoresOp(c1966adf4d8a4a1db4a3861ad448eabd): perf score=3.181125
I20260812 06:17:35.073848  7609 maintenance_manager.cc:643] P 6f8dd1a7e20246ec8c323f9c45330ba1: FlushDeltaMemStoresOp(c1966adf4d8a4a1db4a3861ad448eabd) complete. Timing: real 0.016s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":3881,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:35.074362  7712 maintenance_manager.cc:419] P 6f8dd1a7e20246ec8c323f9c45330ba1: Scheduling UndoDeltaBlockGCOp(c1966adf4d8a4a1db4a3861ad448eabd): 462 bytes on disk
I20260812 06:17:35.074828  7609 maintenance_manager.cc:643] P 6f8dd1a7e20246ec8c323f9c45330ba1: UndoDeltaBlockGCOp(c1966adf4d8a4a1db4a3861ad448eabd) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4}
I20260812 06:17:35.075316  7712 maintenance_manager.cc:419] P 6f8dd1a7e20246ec8c323f9c45330ba1: Scheduling FlushDeltaMemStoresOp(c1966adf4d8a4a1db4a3861ad448eabd): perf score=2.188937
I20260812 06:17:35.088979  7609 maintenance_manager.cc:643] P 6f8dd1a7e20246ec8c323f9c45330ba1: FlushDeltaMemStoresOp(c1966adf4d8a4a1db4a3861ad448eabd) complete. Timing: real 0.014s	user 0.007s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4782,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:35.089586  7712 maintenance_manager.cc:419] P 6f8dd1a7e20246ec8c323f9c45330ba1: Scheduling MajorDeltaCompactionOp(c1966adf4d8a4a1db4a3861ad448eabd): perf score=1.000000
I20260812 06:17:35.264158  7609 maintenance_manager.cc:643] P 6f8dd1a7e20246ec8c323f9c45330ba1: MajorDeltaCompactionOp(c1966adf4d8a4a1db4a3861ad448eabd) complete. Timing: real 0.174s	user 0.134s	sys 0.029s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877329,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":130,"lbm_read_time_us":11255,"lbm_reads_lt_1ms":674,"lbm_write_time_us":33572,"lbm_writes_lt_1ms":643,"mutex_wait_us":26,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":97664,"thread_start_us":71,"threads_started":1,"update_count":3000}
I20260812 06:17:35.264648  7712 maintenance_manager.cc:419] P 6f8dd1a7e20246ec8c323f9c45330ba1: Scheduling FlushDeltaMemStoresOp(c1966adf4d8a4a1db4a3861ad448eabd): perf score=14.095187
I20260812 06:17:35.311285  7609 maintenance_manager.cc:643] P 6f8dd1a7e20246ec8c323f9c45330ba1: FlushDeltaMemStoresOp(c1966adf4d8a4a1db4a3861ad448eabd) complete. Timing: real 0.046s	user 0.028s	sys 0.015s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":19505,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:35.311848  7712 maintenance_manager.cc:419] P 6f8dd1a7e20246ec8c323f9c45330ba1: Scheduling FlushDeltaMemStoresOp(c1966adf4d8a4a1db4a3861ad448eabd): perf score=2.188937
I20260812 06:17:35.331074  7609 maintenance_manager.cc:643] P 6f8dd1a7e20246ec8c323f9c45330ba1: FlushDeltaMemStoresOp(c1966adf4d8a4a1db4a3861ad448eabd) complete. Timing: real 0.019s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5402,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:35.331588  7712 maintenance_manager.cc:419] P 6f8dd1a7e20246ec8c323f9c45330ba1: Scheduling MajorDeltaCompactionOp(c1966adf4d8a4a1db4a3861ad448eabd): perf score=1.000000
I20260812 06:17:35.474941  7609 maintenance_manager.cc:643] P 6f8dd1a7e20246ec8c323f9c45330ba1: MajorDeltaCompactionOp(c1966adf4d8a4a1db4a3861ad448eabd) complete. Timing: real 0.143s	user 0.108s	sys 0.031s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":168,"lbm_read_time_us":10277,"lbm_reads_lt_1ms":564,"lbm_write_time_us":27261,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2560,"update_count":2500}
I20260812 06:17:35.475409  7712 maintenance_manager.cc:419] P 6f8dd1a7e20246ec8c323f9c45330ba1: Scheduling FlushDeltaMemStoresOp(c1966adf4d8a4a1db4a3861ad448eabd): perf score=14.095187
I20260812 06:17:35.523871  7609 maintenance_manager.cc:643] P 6f8dd1a7e20246ec8c323f9c45330ba1: FlushDeltaMemStoresOp(c1966adf4d8a4a1db4a3861ad448eabd) complete. Timing: real 0.048s	user 0.020s	sys 0.025s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22613,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:35.524415  7712 maintenance_manager.cc:419] P 6f8dd1a7e20246ec8c323f9c45330ba1: Scheduling FlushDeltaMemStoresOp(c1966adf4d8a4a1db4a3861ad448eabd): perf score=2.188937
I20260812 06:17:35.540045  7609 maintenance_manager.cc:643] P 6f8dd1a7e20246ec8c323f9c45330ba1: FlushDeltaMemStoresOp(c1966adf4d8a4a1db4a3861ad448eabd) complete. Timing: real 0.015s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5846,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:35.540750  7712 maintenance_manager.cc:419] P 6f8dd1a7e20246ec8c323f9c45330ba1: Scheduling MajorDeltaCompactionOp(c1966adf4d8a4a1db4a3861ad448eabd): perf score=1.000000
I20260812 06:17:35.698098  7609 maintenance_manager.cc:643] P 6f8dd1a7e20246ec8c323f9c45330ba1: MajorDeltaCompactionOp(c1966adf4d8a4a1db4a3861ad448eabd) complete. Timing: real 0.157s	user 0.121s	sys 0.027s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1145,"lbm_read_time_us":10787,"lbm_reads_lt_1ms":564,"lbm_write_time_us":26063,"lbm_writes_lt_1ms":543,"mutex_wait_us":324,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2944,"update_count":2500}
I20260812 06:17:35.698652  7712 maintenance_manager.cc:419] P 6f8dd1a7e20246ec8c323f9c45330ba1: Scheduling FlushDeltaMemStoresOp(c1966adf4d8a4a1db4a3861ad448eabd): perf score=14.095187
I20260812 06:17:35.737066  7609 maintenance_manager.cc:643] P 6f8dd1a7e20246ec8c323f9c45330ba1: FlushDeltaMemStoresOp(c1966adf4d8a4a1db4a3861ad448eabd) complete. Timing: real 0.038s	user 0.026s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":17059,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:35.737639  7712 maintenance_manager.cc:419] P 6f8dd1a7e20246ec8c323f9c45330ba1: Scheduling MajorDeltaCompactionOp(c1966adf4d8a4a1db4a3861ad448eabd): perf score=1.000000
I20260812 06:17:35.876842  7609 maintenance_manager.cc:643] P 6f8dd1a7e20246ec8c323f9c45330ba1: MajorDeltaCompactionOp(c1966adf4d8a4a1db4a3861ad448eabd) complete. Timing: real 0.139s	user 0.106s	sys 0.032s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672157,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":582,"lbm_read_time_us":9282,"lbm_reads_lt_1ms":467,"lbm_write_time_us":22832,"lbm_writes_lt_1ms":443,"mutex_wait_us":295,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":14080,"update_count":2000}
I20260812 06:17:35.877394  7712 maintenance_manager.cc:419] P 6f8dd1a7e20246ec8c323f9c45330ba1: Scheduling FlushDeltaMemStoresOp(c1966adf4d8a4a1db4a3861ad448eabd): perf score=10.126437
I20260812 06:17:35.907037  7609 maintenance_manager.cc:643] P 6f8dd1a7e20246ec8c323f9c45330ba1: FlushDeltaMemStoresOp(c1966adf4d8a4a1db4a3861ad448eabd) complete. Timing: real 0.029s	user 0.019s	sys 0.009s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":12662,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:35.907563  7712 maintenance_manager.cc:419] P 6f8dd1a7e20246ec8c323f9c45330ba1: Scheduling FlushDeltaMemStoresOp(c1966adf4d8a4a1db4a3861ad448eabd): perf score=2.188937
I20260812 06:17:35.921988  7609 maintenance_manager.cc:643] P 6f8dd1a7e20246ec8c323f9c45330ba1: FlushDeltaMemStoresOp(c1966adf4d8a4a1db4a3861ad448eabd) complete. Timing: real 0.014s	user 0.003s	sys 0.010s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5388,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:35.922765  7712 maintenance_manager.cc:419] P 6f8dd1a7e20246ec8c323f9c45330ba1: Scheduling MajorDeltaCompactionOp(c1966adf4d8a4a1db4a3861ad448eabd): perf score=1.000000
I20260812 06:17:36.041951  7609 maintenance_manager.cc:643] P 6f8dd1a7e20246ec8c323f9c45330ba1: MajorDeltaCompactionOp(c1966adf4d8a4a1db4a3861ad448eabd) complete. Timing: real 0.119s	user 0.093s	sys 0.025s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":261,"lbm_read_time_us":7438,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23253,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:36.042480  7712 maintenance_manager.cc:419] P 6f8dd1a7e20246ec8c323f9c45330ba1: Scheduling FlushDeltaMemStoresOp(c1966adf4d8a4a1db4a3861ad448eabd): perf score=10.126437
I20260812 06:17:36.088836  7609 maintenance_manager.cc:643] P 6f8dd1a7e20246ec8c323f9c45330ba1: FlushDeltaMemStoresOp(c1966adf4d8a4a1db4a3861ad448eabd) complete. Timing: real 0.046s	user 0.018s	sys 0.024s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":20152,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:17:36.089416  7712 maintenance_manager.cc:419] P 6f8dd1a7e20246ec8c323f9c45330ba1: Scheduling FlushDeltaMemStoresOp(c1966adf4d8a4a1db4a3861ad448eabd): perf score=2.188937
I20260812 06:17:36.099252  7609 maintenance_manager.cc:643] P 6f8dd1a7e20246ec8c323f9c45330ba1: FlushDeltaMemStoresOp(c1966adf4d8a4a1db4a3861ad448eabd) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3579,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:36.099838  7712 maintenance_manager.cc:419] P 6f8dd1a7e20246ec8c323f9c45330ba1: Scheduling MajorDeltaCompactionOp(c1966adf4d8a4a1db4a3861ad448eabd): perf score=1.000000
I20260812 06:17:36.220400  7609 maintenance_manager.cc:643] P 6f8dd1a7e20246ec8c323f9c45330ba1: MajorDeltaCompactionOp(c1966adf4d8a4a1db4a3861ad448eabd) complete. Timing: real 0.120s	user 0.088s	sys 0.032s 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":554,"lbm_read_time_us":8082,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23978,"lbm_writes_lt_1ms":443,"mutex_wait_us":303,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7680,"update_count":2000}
I20260812 06:17:36.220955  7712 maintenance_manager.cc:419] P 6f8dd1a7e20246ec8c323f9c45330ba1: Scheduling FlushDeltaMemStoresOp(c1966adf4d8a4a1db4a3861ad448eabd): perf score=10.126437
I20260812 06:17:36.264914  7609 maintenance_manager.cc:643] P 6f8dd1a7e20246ec8c323f9c45330ba1: FlushDeltaMemStoresOp(c1966adf4d8a4a1db4a3861ad448eabd) complete. Timing: real 0.044s	user 0.021s	sys 0.012s Metrics: {"bytes_written":12307505,"delete_count":0,"lbm_write_time_us":15717,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:36.265434  7712 maintenance_manager.cc:419] P 6f8dd1a7e20246ec8c323f9c45330ba1: Scheduling FlushDeltaMemStoresOp(c1966adf4d8a4a1db4a3861ad448eabd): perf score=2.188937
I20260812 06:17:36.275247  7609 maintenance_manager.cc:643] P 6f8dd1a7e20246ec8c323f9c45330ba1: FlushDeltaMemStoresOp(c1966adf4d8a4a1db4a3861ad448eabd) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3710,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:36.275969  7712 maintenance_manager.cc:419] P 6f8dd1a7e20246ec8c323f9c45330ba1: Scheduling FlushMRSOp(c1966adf4d8a4a1db4a3861ad448eabd): perf score=1.000000
I20260812 06:17:36.306905  7609 maintenance_manager.cc:643] P 6f8dd1a7e20246ec8c323f9c45330ba1: FlushMRSOp(c1966adf4d8a4a1db4a3861ad448eabd) complete. Timing: real 0.031s	user 0.028s	sys 0.000s Metrics: {"bytes_written":1152514,"cfile_init":1,"dirs.queue_time_us":73,"dirs.run_cpu_time_us":166,"dirs.run_wall_time_us":1006,"drs_written":1,"lbm_read_time_us":72,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2134,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:17:36.307696  7712 maintenance_manager.cc:419] P 6f8dd1a7e20246ec8c323f9c45330ba1: Scheduling LogGCOp(c1966adf4d8a4a1db4a3861ad448eabd): free 124257299 bytes of WAL
I20260812 06:17:36.307951  7609 log_reader.cc:385] T c1966adf4d8a4a1db4a3861ad448eabd: removed 12 log segments from log reader
I20260812 06:17:36.308010  7609 log.cc:1079] T c1966adf4d8a4a1db4a3861ad448eabd P 6f8dd1a7e20246ec8c323f9c45330ba1: Deleting log segment in path: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453282085-7439-0/minicluster-data/ts-0-root/wals/c1966adf4d8a4a1db4a3861ad448eabd/wal-000000014 (ops 66-70)
I20260812 06:17:36.308054  7609 log.cc:1079] T c1966adf4d8a4a1db4a3861ad448eabd P 6f8dd1a7e20246ec8c323f9c45330ba1: Deleting log segment in path: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453282085-7439-0/minicluster-data/ts-0-root/wals/c1966adf4d8a4a1db4a3861ad448eabd/wal-000000015 (ops 71-75)
I20260812 06:17:36.308095  7609 log.cc:1079] T c1966adf4d8a4a1db4a3861ad448eabd P 6f8dd1a7e20246ec8c323f9c45330ba1: Deleting log segment in path: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453282085-7439-0/minicluster-data/ts-0-root/wals/c1966adf4d8a4a1db4a3861ad448eabd/wal-000000016 (ops 76-80)
I20260812 06:17:36.308131  7609 log.cc:1079] T c1966adf4d8a4a1db4a3861ad448eabd P 6f8dd1a7e20246ec8c323f9c45330ba1: Deleting log segment in path: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453282085-7439-0/minicluster-data/ts-0-root/wals/c1966adf4d8a4a1db4a3861ad448eabd/wal-000000017 (ops 81-85)
I20260812 06:17:36.308167  7609 log.cc:1079] T c1966adf4d8a4a1db4a3861ad448eabd P 6f8dd1a7e20246ec8c323f9c45330ba1: Deleting log segment in path: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453282085-7439-0/minicluster-data/ts-0-root/wals/c1966adf4d8a4a1db4a3861ad448eabd/wal-000000018 (ops 86-90)
I20260812 06:17:36.308204  7609 log.cc:1079] T c1966adf4d8a4a1db4a3861ad448eabd P 6f8dd1a7e20246ec8c323f9c45330ba1: Deleting log segment in path: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453282085-7439-0/minicluster-data/ts-0-root/wals/c1966adf4d8a4a1db4a3861ad448eabd/wal-000000019 (ops 91-95)
I20260812 06:17:36.308233  7609 log.cc:1079] T c1966adf4d8a4a1db4a3861ad448eabd P 6f8dd1a7e20246ec8c323f9c45330ba1: Deleting log segment in path: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453282085-7439-0/minicluster-data/ts-0-root/wals/c1966adf4d8a4a1db4a3861ad448eabd/wal-000000020 (ops 96-100)
I20260812 06:17:36.308271  7609 log.cc:1079] T c1966adf4d8a4a1db4a3861ad448eabd P 6f8dd1a7e20246ec8c323f9c45330ba1: Deleting log segment in path: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453282085-7439-0/minicluster-data/ts-0-root/wals/c1966adf4d8a4a1db4a3861ad448eabd/wal-000000021 (ops 101-105)
I20260812 06:17:36.308315  7609 log.cc:1079] T c1966adf4d8a4a1db4a3861ad448eabd P 6f8dd1a7e20246ec8c323f9c45330ba1: Deleting log segment in path: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453282085-7439-0/minicluster-data/ts-0-root/wals/c1966adf4d8a4a1db4a3861ad448eabd/wal-000000022 (ops 106-110)
I20260812 06:17:36.308351  7609 log.cc:1079] T c1966adf4d8a4a1db4a3861ad448eabd P 6f8dd1a7e20246ec8c323f9c45330ba1: Deleting log segment in path: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453282085-7439-0/minicluster-data/ts-0-root/wals/c1966adf4d8a4a1db4a3861ad448eabd/wal-000000023 (ops 111-115)
I20260812 06:17:36.308388  7609 log.cc:1079] T c1966adf4d8a4a1db4a3861ad448eabd P 6f8dd1a7e20246ec8c323f9c45330ba1: Deleting log segment in path: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453282085-7439-0/minicluster-data/ts-0-root/wals/c1966adf4d8a4a1db4a3861ad448eabd/wal-000000024 (ops 116-120)
I20260812 06:17:36.308425  7609 log.cc:1079] T c1966adf4d8a4a1db4a3861ad448eabd P 6f8dd1a7e20246ec8c323f9c45330ba1: Deleting log segment in path: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453282085-7439-0/minicluster-data/ts-0-root/wals/c1966adf4d8a4a1db4a3861ad448eabd/wal-000000025 (ops 121-124)
I20260812 06:17:36.330931  7609 maintenance_manager.cc:643] P 6f8dd1a7e20246ec8c323f9c45330ba1: LogGCOp(c1966adf4d8a4a1db4a3861ad448eabd) complete. Timing: real 0.023s	user 0.002s	sys 0.019s Metrics: {}
I20260812 06:17:36.331444  7712 maintenance_manager.cc:419] P 6f8dd1a7e20246ec8c323f9c45330ba1: Scheduling FlushDeltaMemStoresOp(c1966adf4d8a4a1db4a3861ad448eabd): perf score=3.181125
I20260812 06:17:36.353916  7609 maintenance_manager.cc:643] P 6f8dd1a7e20246ec8c323f9c45330ba1: FlushDeltaMemStoresOp(c1966adf4d8a4a1db4a3861ad448eabd) complete. Timing: real 0.022s	user 0.010s	sys 0.008s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":7561,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:36.354404  7712 maintenance_manager.cc:419] P 6f8dd1a7e20246ec8c323f9c45330ba1: Scheduling UndoDeltaBlockGCOp(c1966adf4d8a4a1db4a3861ad448eabd): 447 bytes on disk
I20260812 06:17:36.354851  7609 maintenance_manager.cc:643] P 6f8dd1a7e20246ec8c323f9c45330ba1: UndoDeltaBlockGCOp(c1966adf4d8a4a1db4a3861ad448eabd) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":62,"lbm_reads_lt_1ms":4}
I20260812 06:17:36.355386  7712 maintenance_manager.cc:419] P 6f8dd1a7e20246ec8c323f9c45330ba1: Scheduling FlushDeltaMemStoresOp(c1966adf4d8a4a1db4a3861ad448eabd): perf score=2.188937
I20260812 06:17:36.368319  7609 maintenance_manager.cc:643] P 6f8dd1a7e20246ec8c323f9c45330ba1: FlushDeltaMemStoresOp(c1966adf4d8a4a1db4a3861ad448eabd) complete. Timing: real 0.013s	user 0.007s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4774,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:36.368960  7712 maintenance_manager.cc:419] P 6f8dd1a7e20246ec8c323f9c45330ba1: Scheduling MajorDeltaCompactionOp(c1966adf4d8a4a1db4a3861ad448eabd): perf score=1.000000
I20260812 06:17:36.536159  7609 maintenance_manager.cc:643] P 6f8dd1a7e20246ec8c323f9c45330ba1: MajorDeltaCompactionOp(c1966adf4d8a4a1db4a3861ad448eabd) complete. Timing: real 0.167s	user 0.127s	sys 0.033s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877344,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1070,"lbm_read_time_us":10301,"lbm_reads_lt_1ms":674,"lbm_write_time_us":32132,"lbm_writes_lt_1ms":643,"mutex_wait_us":312,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1792,"thread_start_us":74,"threads_started":1,"update_count":3000}
I20260812 06:17:36.537343  7712 maintenance_manager.cc:419] P 6f8dd1a7e20246ec8c323f9c45330ba1: Scheduling FlushDeltaMemStoresOp(c1966adf4d8a4a1db4a3861ad448eabd): perf score=14.095187
I20260812 06:17:36.583992  7609 maintenance_manager.cc:643] P 6f8dd1a7e20246ec8c323f9c45330ba1: FlushDeltaMemStoresOp(c1966adf4d8a4a1db4a3861ad448eabd) complete. Timing: real 0.046s	user 0.022s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":17693,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:36.584484  7712 maintenance_manager.cc:419] P 6f8dd1a7e20246ec8c323f9c45330ba1: Scheduling FlushDeltaMemStoresOp(c1966adf4d8a4a1db4a3861ad448eabd): perf score=2.188937
I20260812 06:17:36.594929  7609 maintenance_manager.cc:643] P 6f8dd1a7e20246ec8c323f9c45330ba1: FlushDeltaMemStoresOp(c1966adf4d8a4a1db4a3861ad448eabd) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3717,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:36.595515  7712 maintenance_manager.cc:419] P 6f8dd1a7e20246ec8c323f9c45330ba1: Scheduling MajorDeltaCompactionOp(c1966adf4d8a4a1db4a3861ad448eabd): perf score=1.000000
I20260812 06:17:36.736773  7609 maintenance_manager.cc:643] P 6f8dd1a7e20246ec8c323f9c45330ba1: MajorDeltaCompactionOp(c1966adf4d8a4a1db4a3861ad448eabd) complete. Timing: real 0.141s	user 0.103s	sys 0.036s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":265,"lbm_read_time_us":11429,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25089,"lbm_writes_lt_1ms":543,"mutex_wait_us":56,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4352,"update_count":2500}
I20260812 06:17:36.737293  7712 maintenance_manager.cc:419] P 6f8dd1a7e20246ec8c323f9c45330ba1: Scheduling FlushDeltaMemStoresOp(c1966adf4d8a4a1db4a3861ad448eabd): perf score=12.110812
I20260812 06:17:36.776454  7609 maintenance_manager.cc:643] P 6f8dd1a7e20246ec8c323f9c45330ba1: FlushDeltaMemStoresOp(c1966adf4d8a4a1db4a3861ad448eabd) complete. Timing: real 0.039s	user 0.021s	sys 0.015s Metrics: {"bytes_written":13579242,"delete_count":0,"lbm_write_time_us":17225,"lbm_writes_lt_1ms":334,"reinsert_count":0,"update_count":1655}
I20260812 06:17:36.777046  7712 maintenance_manager.cc:419] P 6f8dd1a7e20246ec8c323f9c45330ba1: Scheduling FlushDeltaMemStoresOp(c1966adf4d8a4a1db4a3861ad448eabd): perf score=1.196750
I20260812 06:17:36.797516  7609 maintenance_manager.cc:643] P 6f8dd1a7e20246ec8c323f9c45330ba1: FlushDeltaMemStoresOp(c1966adf4d8a4a1db4a3861ad448eabd) complete. Timing: real 0.020s	user 0.008s	sys 0.001s Metrics: {"bytes_written":2830880,"delete_count":0,"lbm_write_time_us":3409,"lbm_writes_lt_1ms":72,"reinsert_count":0,"update_count":345}
I20260812 06:17:36.797986  7712 maintenance_manager.cc:419] P 6f8dd1a7e20246ec8c323f9c45330ba1: Scheduling FlushDeltaMemStoresOp(c1966adf4d8a4a1db4a3861ad448eabd): perf score=2.188937
I20260812 06:17:36.812306  7609 maintenance_manager.cc:643] P 6f8dd1a7e20246ec8c323f9c45330ba1: FlushDeltaMemStoresOp(c1966adf4d8a4a1db4a3861ad448eabd) complete. Timing: real 0.014s	user 0.004s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5239,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:36.812814  7712 maintenance_manager.cc:419] P 6f8dd1a7e20246ec8c323f9c45330ba1: Scheduling MajorDeltaCompactionOp(c1966adf4d8a4a1db4a3861ad448eabd): perf score=1.000000
I20260812 06:17:36.974329  7609 maintenance_manager.cc:643] P 6f8dd1a7e20246ec8c323f9c45330ba1: MajorDeltaCompactionOp(c1966adf4d8a4a1db4a3861ad448eabd) complete. Timing: real 0.161s	user 0.114s	sys 0.044s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774781,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":575,"lbm_read_time_us":11390,"lbm_reads_lt_1ms":573,"lbm_write_time_us":29094,"lbm_writes_lt_1ms":543,"mutex_wait_us":36,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2500}
I20260812 06:17:36.975179  7712 maintenance_manager.cc:419] P 6f8dd1a7e20246ec8c323f9c45330ba1: Scheduling FlushDeltaMemStoresOp(c1966adf4d8a4a1db4a3861ad448eabd): perf score=14.095187
I20260812 06:17:37.030839  7609 maintenance_manager.cc:643] P 6f8dd1a7e20246ec8c323f9c45330ba1: FlushDeltaMemStoresOp(c1966adf4d8a4a1db4a3861ad448eabd) complete. Timing: real 0.055s	user 0.029s	sys 0.015s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20317,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:37.031448  7712 maintenance_manager.cc:419] P 6f8dd1a7e20246ec8c323f9c45330ba1: Scheduling FlushDeltaMemStoresOp(c1966adf4d8a4a1db4a3861ad448eabd): perf score=2.188937
I20260812 06:17:37.042944  7609 maintenance_manager.cc:643] P 6f8dd1a7e20246ec8c323f9c45330ba1: FlushDeltaMemStoresOp(c1966adf4d8a4a1db4a3861ad448eabd) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4163,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:37.043499  7712 maintenance_manager.cc:419] P 6f8dd1a7e20246ec8c323f9c45330ba1: Scheduling MajorDeltaCompactionOp(c1966adf4d8a4a1db4a3861ad448eabd): perf score=1.000000
I20260812 06:17:37.215543  7609 maintenance_manager.cc:643] P 6f8dd1a7e20246ec8c323f9c45330ba1: MajorDeltaCompactionOp(c1966adf4d8a4a1db4a3861ad448eabd) complete. Timing: real 0.172s	user 0.127s	sys 0.038s 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":958,"lbm_read_time_us":12211,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29062,"lbm_writes_lt_1ms":543,"mutex_wait_us":306,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9472,"update_count":2500}
I20260812 06:17:37.216099  7712 maintenance_manager.cc:419] P 6f8dd1a7e20246ec8c323f9c45330ba1: Scheduling FlushDeltaMemStoresOp(c1966adf4d8a4a1db4a3861ad448eabd): perf score=14.095187
I20260812 06:17:37.268927  7609 maintenance_manager.cc:643] P 6f8dd1a7e20246ec8c323f9c45330ba1: FlushDeltaMemStoresOp(c1966adf4d8a4a1db4a3861ad448eabd) complete. Timing: real 0.053s	user 0.023s	sys 0.019s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":16974,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:37.269469  7712 maintenance_manager.cc:419] P 6f8dd1a7e20246ec8c323f9c45330ba1: Scheduling FlushDeltaMemStoresOp(c1966adf4d8a4a1db4a3861ad448eabd): perf score=2.188937
I20260812 06:17:37.279532  7609 maintenance_manager.cc:643] P 6f8dd1a7e20246ec8c323f9c45330ba1: FlushDeltaMemStoresOp(c1966adf4d8a4a1db4a3861ad448eabd) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3742,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:37.279975  7712 maintenance_manager.cc:419] P 6f8dd1a7e20246ec8c323f9c45330ba1: Scheduling MajorDeltaCompactionOp(c1966adf4d8a4a1db4a3861ad448eabd): perf score=1.000000
I20260812 06:17:37.446224  7609 maintenance_manager.cc:643] P 6f8dd1a7e20246ec8c323f9c45330ba1: MajorDeltaCompactionOp(c1966adf4d8a4a1db4a3861ad448eabd) complete. Timing: real 0.166s	user 0.102s	sys 0.056s 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":289,"lbm_read_time_us":12354,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27397,"lbm_writes_lt_1ms":543,"mutex_wait_us":71,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:17:37.446754  7712 maintenance_manager.cc:419] P 6f8dd1a7e20246ec8c323f9c45330ba1: Scheduling FlushDeltaMemStoresOp(c1966adf4d8a4a1db4a3861ad448eabd): perf score=14.095187
I20260812 06:17:37.504297  7609 maintenance_manager.cc:643] P 6f8dd1a7e20246ec8c323f9c45330ba1: FlushDeltaMemStoresOp(c1966adf4d8a4a1db4a3861ad448eabd) complete. Timing: real 0.057s	user 0.015s	sys 0.031s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":18149,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:37.504848  7712 maintenance_manager.cc:419] P 6f8dd1a7e20246ec8c323f9c45330ba1: Scheduling FlushDeltaMemStoresOp(c1966adf4d8a4a1db4a3861ad448eabd): perf score=2.188937
I20260812 06:17:37.520231  7609 maintenance_manager.cc:643] P 6f8dd1a7e20246ec8c323f9c45330ba1: FlushDeltaMemStoresOp(c1966adf4d8a4a1db4a3861ad448eabd) complete. Timing: real 0.015s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5775,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:37.520733  7712 maintenance_manager.cc:419] P 6f8dd1a7e20246ec8c323f9c45330ba1: Scheduling MajorDeltaCompactionOp(c1966adf4d8a4a1db4a3861ad448eabd): perf score=1.000000
I20260812 06:17:37.698014  7609 maintenance_manager.cc:643] P 6f8dd1a7e20246ec8c323f9c45330ba1: MajorDeltaCompactionOp(c1966adf4d8a4a1db4a3861ad448eabd) complete. Timing: real 0.177s	user 0.110s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":179,"lbm_read_time_us":11646,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27157,"lbm_writes_lt_1ms":543,"mutex_wait_us":44,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":20736,"update_count":2500}
I20260812 06:17:37.698578  7712 maintenance_manager.cc:419] P 6f8dd1a7e20246ec8c323f9c45330ba1: Scheduling FlushDeltaMemStoresOp(c1966adf4d8a4a1db4a3861ad448eabd): perf score=14.095187
I20260812 06:17:37.746879  7609 maintenance_manager.cc:643] P 6f8dd1a7e20246ec8c323f9c45330ba1: FlushDeltaMemStoresOp(c1966adf4d8a4a1db4a3861ad448eabd) complete. Timing: real 0.048s	user 0.035s	sys 0.008s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19223,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:37.747480  7712 maintenance_manager.cc:419] P 6f8dd1a7e20246ec8c323f9c45330ba1: Scheduling FlushDeltaMemStoresOp(c1966adf4d8a4a1db4a3861ad448eabd): perf score=2.188937
I20260812 06:17:37.764470  7609 maintenance_manager.cc:643] P 6f8dd1a7e20246ec8c323f9c45330ba1: FlushDeltaMemStoresOp(c1966adf4d8a4a1db4a3861ad448eabd) complete. Timing: real 0.017s	user 0.008s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3803,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:37.765074  7712 maintenance_manager.cc:419] P 6f8dd1a7e20246ec8c323f9c45330ba1: Scheduling FlushMRSOp(c1966adf4d8a4a1db4a3861ad448eabd): perf score=1.000000
I20260812 06:17:37.804577  7609 maintenance_manager.cc:643] P 6f8dd1a7e20246ec8c323f9c45330ba1: FlushMRSOp(c1966adf4d8a4a1db4a3861ad448eabd) complete. Timing: real 0.039s	user 0.034s	sys 0.001s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":65,"dirs.run_cpu_time_us":215,"dirs.run_wall_time_us":1278,"drs_written":1,"lbm_read_time_us":64,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2128,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:17:37.805478  7712 maintenance_manager.cc:419] P 6f8dd1a7e20246ec8c323f9c45330ba1: Scheduling LogGCOp(c1966adf4d8a4a1db4a3861ad448eabd): free 129773825 bytes of WAL
I20260812 06:17:37.805751  7609 log_reader.cc:385] T c1966adf4d8a4a1db4a3861ad448eabd: removed 13 log segments from log reader
I20260812 06:17:37.805819  7609 log.cc:1079] T c1966adf4d8a4a1db4a3861ad448eabd P 6f8dd1a7e20246ec8c323f9c45330ba1: Deleting log segment in path: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453282085-7439-0/minicluster-data/ts-0-root/wals/c1966adf4d8a4a1db4a3861ad448eabd/wal-000000026 (ops 125-129)
I20260812 06:17:37.805868  7609 log.cc:1079] T c1966adf4d8a4a1db4a3861ad448eabd P 6f8dd1a7e20246ec8c323f9c45330ba1: Deleting log segment in path: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453282085-7439-0/minicluster-data/ts-0-root/wals/c1966adf4d8a4a1db4a3861ad448eabd/wal-000000027 (ops 130-134)
I20260812 06:17:37.805899  7609 log.cc:1079] T c1966adf4d8a4a1db4a3861ad448eabd P 6f8dd1a7e20246ec8c323f9c45330ba1: Deleting log segment in path: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453282085-7439-0/minicluster-data/ts-0-root/wals/c1966adf4d8a4a1db4a3861ad448eabd/wal-000000028 (ops 135-138)
I20260812 06:17:37.805930  7609 log.cc:1079] T c1966adf4d8a4a1db4a3861ad448eabd P 6f8dd1a7e20246ec8c323f9c45330ba1: Deleting log segment in path: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453282085-7439-0/minicluster-data/ts-0-root/wals/c1966adf4d8a4a1db4a3861ad448eabd/wal-000000029 (ops 139-143)
I20260812 06:17:37.805962  7609 log.cc:1079] T c1966adf4d8a4a1db4a3861ad448eabd P 6f8dd1a7e20246ec8c323f9c45330ba1: Deleting log segment in path: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453282085-7439-0/minicluster-data/ts-0-root/wals/c1966adf4d8a4a1db4a3861ad448eabd/wal-000000030 (ops 144-149)
I20260812 06:17:37.805995  7609 log.cc:1079] T c1966adf4d8a4a1db4a3861ad448eabd P 6f8dd1a7e20246ec8c323f9c45330ba1: Deleting log segment in path: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453282085-7439-0/minicluster-data/ts-0-root/wals/c1966adf4d8a4a1db4a3861ad448eabd/wal-000000031 (ops 150-154)
I20260812 06:17:37.806022  7609 log.cc:1079] T c1966adf4d8a4a1db4a3861ad448eabd P 6f8dd1a7e20246ec8c323f9c45330ba1: Deleting log segment in path: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453282085-7439-0/minicluster-data/ts-0-root/wals/c1966adf4d8a4a1db4a3861ad448eabd/wal-000000032 (ops 155-159)
I20260812 06:17:37.806051  7609 log.cc:1079] T c1966adf4d8a4a1db4a3861ad448eabd P 6f8dd1a7e20246ec8c323f9c45330ba1: Deleting log segment in path: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453282085-7439-0/minicluster-data/ts-0-root/wals/c1966adf4d8a4a1db4a3861ad448eabd/wal-000000033 (ops 160-164)
I20260812 06:17:37.806078  7609 log.cc:1079] T c1966adf4d8a4a1db4a3861ad448eabd P 6f8dd1a7e20246ec8c323f9c45330ba1: Deleting log segment in path: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453282085-7439-0/minicluster-data/ts-0-root/wals/c1966adf4d8a4a1db4a3861ad448eabd/wal-000000034 (ops 165-168)
I20260812 06:17:37.806109  7609 log.cc:1079] T c1966adf4d8a4a1db4a3861ad448eabd P 6f8dd1a7e20246ec8c323f9c45330ba1: Deleting log segment in path: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453282085-7439-0/minicluster-data/ts-0-root/wals/c1966adf4d8a4a1db4a3861ad448eabd/wal-000000035 (ops 169-173)
I20260812 06:17:37.806140  7609 log.cc:1079] T c1966adf4d8a4a1db4a3861ad448eabd P 6f8dd1a7e20246ec8c323f9c45330ba1: Deleting log segment in path: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453282085-7439-0/minicluster-data/ts-0-root/wals/c1966adf4d8a4a1db4a3861ad448eabd/wal-000000036 (ops 174-178)
I20260812 06:17:37.806167  7609 log.cc:1079] T c1966adf4d8a4a1db4a3861ad448eabd P 6f8dd1a7e20246ec8c323f9c45330ba1: Deleting log segment in path: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453282085-7439-0/minicluster-data/ts-0-root/wals/c1966adf4d8a4a1db4a3861ad448eabd/wal-000000037 (ops 179-183)
I20260812 06:17:37.806195  7609 log.cc:1079] T c1966adf4d8a4a1db4a3861ad448eabd P 6f8dd1a7e20246ec8c323f9c45330ba1: Deleting log segment in path: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515453282085-7439-0/minicluster-data/ts-0-root/wals/c1966adf4d8a4a1db4a3861ad448eabd/wal-000000038 (ops 184-188)
I20260812 06:17:37.836241  7609 maintenance_manager.cc:643] P 6f8dd1a7e20246ec8c323f9c45330ba1: LogGCOp(c1966adf4d8a4a1db4a3861ad448eabd) complete. Timing: real 0.031s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:17:37.836683  7712 maintenance_manager.cc:419] P 6f8dd1a7e20246ec8c323f9c45330ba1: Scheduling UndoDeltaBlockGCOp(c1966adf4d8a4a1db4a3861ad448eabd): 492 bytes on disk
I20260812 06:17:37.837149  7609 maintenance_manager.cc:643] P 6f8dd1a7e20246ec8c323f9c45330ba1: UndoDeltaBlockGCOp(c1966adf4d8a4a1db4a3861ad448eabd) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4}
I20260812 06:17:37.837813  7712 maintenance_manager.cc:419] P 6f8dd1a7e20246ec8c323f9c45330ba1: Scheduling FlushDeltaMemStoresOp(c1966adf4d8a4a1db4a3861ad448eabd): perf score=3.181125
I20260812 06:17:37.853497  7609 maintenance_manager.cc:643] P 6f8dd1a7e20246ec8c323f9c45330ba1: FlushDeltaMemStoresOp(c1966adf4d8a4a1db4a3861ad448eabd) complete. Timing: real 0.015s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4138,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:37.853951  7712 maintenance_manager.cc:419] P 6f8dd1a7e20246ec8c323f9c45330ba1: Scheduling FlushDeltaMemStoresOp(c1966adf4d8a4a1db4a3861ad448eabd): perf score=2.188937
I20260812 06:17:37.864705  7609 maintenance_manager.cc:643] P 6f8dd1a7e20246ec8c323f9c45330ba1: FlushDeltaMemStoresOp(c1966adf4d8a4a1db4a3861ad448eabd) complete. Timing: real 0.011s	user 0.001s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3713,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:37.865335  7712 maintenance_manager.cc:419] P 6f8dd1a7e20246ec8c323f9c45330ba1: Scheduling MajorDeltaCompactionOp(c1966adf4d8a4a1db4a3861ad448eabd): perf score=1.000000
I20260812 06:17:38.101720  7439 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.556s	user 1.694s	sys 0.101s
I20260812 06:17:38.114185  7609 maintenance_manager.cc:643] P 6f8dd1a7e20246ec8c323f9c45330ba1: MajorDeltaCompactionOp(c1966adf4d8a4a1db4a3861ad448eabd) complete. Timing: real 0.249s	user 0.159s	sys 0.077s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979738,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":883,"lbm_read_time_us":23248,"lbm_reads_1-10_ms":2,"lbm_reads_lt_1ms":772,"lbm_write_time_us":38080,"lbm_writes_lt_1ms":743,"mutex_wait_us":78,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":106,"threads_started":1,"update_count":3500}
I20260812 06:17:38.114893  7712 maintenance_manager.cc:419] P 6f8dd1a7e20246ec8c323f9c45330ba1: Scheduling FlushDeltaMemStoresOp(c1966adf4d8a4a1db4a3861ad448eabd): perf score=18.063937
I20260812 06:17:38.154697  7439 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.052s	user 0.002s	sys 0.000s
I20260812 06:17:38.155385  7439 tablet_server.cc:179] TabletServer@127.7.67.193:0 shutting down...
I20260812 06:17:38.168947  7609 maintenance_manager.cc:643] P 6f8dd1a7e20246ec8c323f9c45330ba1: FlushDeltaMemStoresOp(c1966adf4d8a4a1db4a3861ad448eabd) complete. Timing: real 0.054s	user 0.029s	sys 0.020s Metrics: {"bytes_written":20512321,"delete_count":0,"lbm_write_time_us":24276,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:38.169536  7439 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:38.169940  7439 tablet_replica.cc:333] T c1966adf4d8a4a1db4a3861ad448eabd P 6f8dd1a7e20246ec8c323f9c45330ba1: stopping tablet replica
I20260812 06:17:38.170174  7439 raft_consensus.cc:2243] T c1966adf4d8a4a1db4a3861ad448eabd P 6f8dd1a7e20246ec8c323f9c45330ba1 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:38.170408  7439 raft_consensus.cc:2272] T c1966adf4d8a4a1db4a3861ad448eabd P 6f8dd1a7e20246ec8c323f9c45330ba1 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:38.184773  7439 tablet_server.cc:196] TabletServer@127.7.67.193:0 shutdown complete.
I20260812 06:17:38.189342  7439 master.cc:562] Master@127.7.67.254:46335 shutting down...
I20260812 06:17:38.192399  7439 raft_consensus.cc:2243] T 00000000000000000000000000000000 P dce11d4350af4411b4fd4b0a0d198147 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:38.192566  7439 raft_consensus.cc:2272] T 00000000000000000000000000000000 P dce11d4350af4411b4fd4b0a0d198147 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:38.192646  7439 tablet_replica.cc:333] T 00000000000000000000000000000000 P dce11d4350af4411b4fd4b0a0d198147: stopping tablet replica
I20260812 06:17:38.204800  7439 master.cc:584] Master@127.7.67.254:46335 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (4989 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:17:38.280951  7439 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.7.67.254:41275
I20260812 06:17:38.281375  7439 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:38.283154  7768 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:17:38.283344  7761 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:17:38.283208  7766 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:17:38.283474  7439 server_base.cc:1061] running on GCE node
I20260812 06:17:38.283609  7439 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:38.283643  7439 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:17:38.283663  7439 hybrid_clock.cc:648] HybridClock initialized: now 1786515458283663 us; error 0 us; skew 500 ppm
I20260812 06:17:38.284454  7439 webserver.cc:533] Webserver started at http://127.7.67.254:37461/ using document root <none> and password file <none>
I20260812 06:17:38.284613  7439 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:38.284664  7439 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:38.284740  7439 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:38.285147  7439 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453282085-7439-0/minicluster-data/master-0-root/instance:
uuid: "1fe80eb201474722b54f4aeac2a34b24"
format_stamp: "Formatted at 2026-08-12 06:17:38 on dist-test-slave-k5rr"
I20260812 06:17:38.286562  7439 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:38.287472  7783 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:17:38.287689  7439 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:38.287760  7439 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453282085-7439-0/minicluster-data/master-0-root
uuid: "1fe80eb201474722b54f4aeac2a34b24"
format_stamp: "Formatted at 2026-08-12 06:17:38 on dist-test-slave-k5rr"
I20260812 06:17:38.287829  7439 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453282085-7439-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453282085-7439-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453282085-7439-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:17:38.294128  7439 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:38.294428  7439 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:38.298771  7439 rpc_server.cc:307] RPC server started. Bound to: 127.7.67.254:41275
I20260812 06:17:38.310240  7863 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.7.67.254:41275 every 8 connection(s)
I20260812 06:17:38.310658  7866 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:17:38.312361  7866 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 1fe80eb201474722b54f4aeac2a34b24: Bootstrap starting.
I20260812 06:17:38.313145  7866 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 1fe80eb201474722b54f4aeac2a34b24: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:38.314059  7866 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 1fe80eb201474722b54f4aeac2a34b24: No bootstrap required, opened a new log
I20260812 06:17:38.314425  7866 raft_consensus.cc:359] T 00000000000000000000000000000000 P 1fe80eb201474722b54f4aeac2a34b24 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1fe80eb201474722b54f4aeac2a34b24" member_type: VOTER }
I20260812 06:17:38.314507  7866 raft_consensus.cc:385] T 00000000000000000000000000000000 P 1fe80eb201474722b54f4aeac2a34b24 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:38.314527  7866 raft_consensus.cc:740] T 00000000000000000000000000000000 P 1fe80eb201474722b54f4aeac2a34b24 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 1fe80eb201474722b54f4aeac2a34b24, State: Initialized, Role: FOLLOWER
I20260812 06:17:38.314646  7866 consensus_queue.cc:260] T 00000000000000000000000000000000 P 1fe80eb201474722b54f4aeac2a34b24 [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: "1fe80eb201474722b54f4aeac2a34b24" member_type: VOTER }
I20260812 06:17:38.314733  7866 raft_consensus.cc:399] T 00000000000000000000000000000000 P 1fe80eb201474722b54f4aeac2a34b24 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:38.314764  7866 raft_consensus.cc:493] T 00000000000000000000000000000000 P 1fe80eb201474722b54f4aeac2a34b24 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:38.314792  7866 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 1fe80eb201474722b54f4aeac2a34b24 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:38.315413  7866 raft_consensus.cc:515] T 00000000000000000000000000000000 P 1fe80eb201474722b54f4aeac2a34b24 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1fe80eb201474722b54f4aeac2a34b24" member_type: VOTER }
I20260812 06:17:38.315527  7866 leader_election.cc:304] T 00000000000000000000000000000000 P 1fe80eb201474722b54f4aeac2a34b24 [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: 1fe80eb201474722b54f4aeac2a34b24; no voters: 
I20260812 06:17:38.315665  7866 leader_election.cc:290] T 00000000000000000000000000000000 P 1fe80eb201474722b54f4aeac2a34b24 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:38.315783  7873 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 1fe80eb201474722b54f4aeac2a34b24 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:38.315979  7873 raft_consensus.cc:697] T 00000000000000000000000000000000 P 1fe80eb201474722b54f4aeac2a34b24 [term 1 LEADER]: Becoming Leader. State: Replica: 1fe80eb201474722b54f4aeac2a34b24, State: Running, Role: LEADER
I20260812 06:17:38.316072  7866 sys_catalog.cc:565] T 00000000000000000000000000000000 P 1fe80eb201474722b54f4aeac2a34b24 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:38.316169  7873 consensus_queue.cc:237] T 00000000000000000000000000000000 P 1fe80eb201474722b54f4aeac2a34b24 [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: "1fe80eb201474722b54f4aeac2a34b24" member_type: VOTER }
I20260812 06:17:38.316592  7874 sys_catalog.cc:455] T 00000000000000000000000000000000 P 1fe80eb201474722b54f4aeac2a34b24 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "1fe80eb201474722b54f4aeac2a34b24" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1fe80eb201474722b54f4aeac2a34b24" member_type: VOTER } }
I20260812 06:17:38.316606  7876 sys_catalog.cc:455] T 00000000000000000000000000000000 P 1fe80eb201474722b54f4aeac2a34b24 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 1fe80eb201474722b54f4aeac2a34b24. Latest consensus state: current_term: 1 leader_uuid: "1fe80eb201474722b54f4aeac2a34b24" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1fe80eb201474722b54f4aeac2a34b24" member_type: VOTER } }
I20260812 06:17:38.316708  7876 sys_catalog.cc:458] T 00000000000000000000000000000000 P 1fe80eb201474722b54f4aeac2a34b24 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:38.316951  7874 sys_catalog.cc:458] T 00000000000000000000000000000000 P 1fe80eb201474722b54f4aeac2a34b24 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:38.316962  7882 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:38.318025  7882 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:38.318235  7439 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:38.319810  7882 catalog_manager.cc:1383] Generated new cluster ID: c384affb9dc84ca893c0aed7ff0e12ca
I20260812 06:17:38.319867  7882 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:38.341418  7882 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:38.341979  7882 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:38.347246  7882 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 1fe80eb201474722b54f4aeac2a34b24: Generated new TSK 0
I20260812 06:17:38.347407  7882 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:38.350461  7439 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:38.352217  7911 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:17:38.352378  7907 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:17:38.352280  7913 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:17:38.352293  7439 server_base.cc:1061] running on GCE node
I20260812 06:17:38.352620  7439 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:38.352664  7439 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:17:38.352679  7439 hybrid_clock.cc:648] HybridClock initialized: now 1786515458352680 us; error 0 us; skew 500 ppm
I20260812 06:17:38.353526  7439 webserver.cc:533] Webserver started at http://127.7.67.193:39711/ using document root <none> and password file <none>
I20260812 06:17:38.353657  7439 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:38.353695  7439 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:38.353749  7439 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:38.354107  7439 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453282085-7439-0/minicluster-data/ts-0-root/instance:
uuid: "252f1baa290545ba8194ed1157e93dc2"
format_stamp: "Formatted at 2026-08-12 06:17:38 on dist-test-slave-k5rr"
I20260812 06:17:38.355495  7439 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:17:38.356385  7921 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:17:38.356606  7439 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:38.356670  7439 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453282085-7439-0/minicluster-data/ts-0-root
uuid: "252f1baa290545ba8194ed1157e93dc2"
format_stamp: "Formatted at 2026-08-12 06:17:38 on dist-test-slave-k5rr"
I20260812 06:17:38.356738  7439 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453282085-7439-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453282085-7439-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453282085-7439-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:17:38.367635  7439 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:38.367983  7439 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:38.368264  7439 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:38.368724  7439 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:38.368773  7439 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:38.368818  7439 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:38.368842  7439 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:38.372730  7439 rpc_server.cc:307] RPC server started. Bound to: 127.7.67.193:44323
I20260812 06:17:38.372771  8025 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.7.67.193:44323 every 8 connection(s)
I20260812 06:17:38.378162  8028 heartbeater.cc:344] Connected to a master server at 127.7.67.254:41275
I20260812 06:17:38.378257  8028 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:38.378443  8028 heartbeater.cc:507] Master 127.7.67.254:41275 requested a full tablet report, sending...
I20260812 06:17:38.379000  7807 ts_manager.cc:194] Registered new tserver with Master: 252f1baa290545ba8194ed1157e93dc2 (127.7.67.193:44323)
I20260812 06:17:38.379055  7439 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.005858803s
I20260812 06:17:38.379968  7807 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:47958
I20260812 06:17:38.385504  7807 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:47972:
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:17:38.393792  7965 tablet_service.cc:1511] Processing CreateTablet for tablet 507bc7fc24ec49d7958b870a11d5c0ad (DEFAULT_TABLE table=heavy-update-compaction-test [id=20d86710a1854fbf8f2f73079daa85a6]), partition=
I20260812 06:17:38.394045  7965 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 507bc7fc24ec49d7958b870a11d5c0ad. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:38.395828  8045 tablet_bootstrap.cc:492] T 507bc7fc24ec49d7958b870a11d5c0ad P 252f1baa290545ba8194ed1157e93dc2: Bootstrap starting.
I20260812 06:17:38.396678  8045 tablet_bootstrap.cc:654] T 507bc7fc24ec49d7958b870a11d5c0ad P 252f1baa290545ba8194ed1157e93dc2: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:38.397687  8045 tablet_bootstrap.cc:492] T 507bc7fc24ec49d7958b870a11d5c0ad P 252f1baa290545ba8194ed1157e93dc2: No bootstrap required, opened a new log
I20260812 06:17:38.397763  8045 ts_tablet_manager.cc:1403] T 507bc7fc24ec49d7958b870a11d5c0ad P 252f1baa290545ba8194ed1157e93dc2: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:17:38.398125  8045 raft_consensus.cc:359] T 507bc7fc24ec49d7958b870a11d5c0ad P 252f1baa290545ba8194ed1157e93dc2 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "252f1baa290545ba8194ed1157e93dc2" member_type: VOTER last_known_addr { host: "127.7.67.193" port: 44323 } }
I20260812 06:17:38.398208  8045 raft_consensus.cc:385] T 507bc7fc24ec49d7958b870a11d5c0ad P 252f1baa290545ba8194ed1157e93dc2 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:38.398233  8045 raft_consensus.cc:740] T 507bc7fc24ec49d7958b870a11d5c0ad P 252f1baa290545ba8194ed1157e93dc2 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 252f1baa290545ba8194ed1157e93dc2, State: Initialized, Role: FOLLOWER
I20260812 06:17:38.398355  8045 consensus_queue.cc:260] T 507bc7fc24ec49d7958b870a11d5c0ad P 252f1baa290545ba8194ed1157e93dc2 [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: "252f1baa290545ba8194ed1157e93dc2" member_type: VOTER last_known_addr { host: "127.7.67.193" port: 44323 } }
I20260812 06:17:38.398452  8045 raft_consensus.cc:399] T 507bc7fc24ec49d7958b870a11d5c0ad P 252f1baa290545ba8194ed1157e93dc2 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:38.398478  8045 raft_consensus.cc:493] T 507bc7fc24ec49d7958b870a11d5c0ad P 252f1baa290545ba8194ed1157e93dc2 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:38.398507  8045 raft_consensus.cc:3060] T 507bc7fc24ec49d7958b870a11d5c0ad P 252f1baa290545ba8194ed1157e93dc2 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:38.399273  8045 raft_consensus.cc:515] T 507bc7fc24ec49d7958b870a11d5c0ad P 252f1baa290545ba8194ed1157e93dc2 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "252f1baa290545ba8194ed1157e93dc2" member_type: VOTER last_known_addr { host: "127.7.67.193" port: 44323 } }
I20260812 06:17:38.399431  8045 leader_election.cc:304] T 507bc7fc24ec49d7958b870a11d5c0ad P 252f1baa290545ba8194ed1157e93dc2 [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: 252f1baa290545ba8194ed1157e93dc2; no voters: 
I20260812 06:17:38.399607  8045 leader_election.cc:290] T 507bc7fc24ec49d7958b870a11d5c0ad P 252f1baa290545ba8194ed1157e93dc2 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:38.399704  8047 raft_consensus.cc:2804] T 507bc7fc24ec49d7958b870a11d5c0ad P 252f1baa290545ba8194ed1157e93dc2 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:38.399894  8045 ts_tablet_manager.cc:1434] T 507bc7fc24ec49d7958b870a11d5c0ad P 252f1baa290545ba8194ed1157e93dc2: Time spent starting tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:38.399922  8047 raft_consensus.cc:697] T 507bc7fc24ec49d7958b870a11d5c0ad P 252f1baa290545ba8194ed1157e93dc2 [term 1 LEADER]: Becoming Leader. State: Replica: 252f1baa290545ba8194ed1157e93dc2, State: Running, Role: LEADER
I20260812 06:17:38.399937  8028 heartbeater.cc:499] Master 127.7.67.254:41275 was elected leader, sending a full tablet report...
I20260812 06:17:38.400116  8047 consensus_queue.cc:237] T 507bc7fc24ec49d7958b870a11d5c0ad P 252f1baa290545ba8194ed1157e93dc2 [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: "252f1baa290545ba8194ed1157e93dc2" member_type: VOTER last_known_addr { host: "127.7.67.193" port: 44323 } }
I20260812 06:17:38.401458  7807 catalog_manager.cc:5719] T 507bc7fc24ec49d7958b870a11d5c0ad P 252f1baa290545ba8194ed1157e93dc2 reported cstate change: term changed from 0 to 1, leader changed from <none> to 252f1baa290545ba8194ed1157e93dc2 (127.7.67.193). New cstate: current_term: 1 leader_uuid: "252f1baa290545ba8194ed1157e93dc2" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "252f1baa290545ba8194ed1157e93dc2" member_type: VOTER last_known_addr { host: "127.7.67.193" port: 44323 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:38.454977  7439 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.050s	user 0.018s	sys 0.004s
I20260812 06:17:38.623883  8030 maintenance_manager.cc:419] P 252f1baa290545ba8194ed1157e93dc2: Scheduling FlushMRSOp(507bc7fc24ec49d7958b870a11d5c0ad): perf score=23.023690
I20260812 06:17:38.775493  7932 maintenance_manager.cc:643] P 252f1baa290545ba8194ed1157e93dc2: FlushMRSOp(507bc7fc24ec49d7958b870a11d5c0ad) complete. Timing: real 0.151s	user 0.121s	sys 0.028s Metrics: {"bytes_written":12799774,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":72,"dirs.run_cpu_time_us":180,"dirs.run_wall_time_us":725,"drs_written":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4,"lbm_write_time_us":38883,"lbm_writes_lt_1ms":869,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"spinlock_wait_cycles":5376,"update_count":1560}
I20260812 06:17:38.776182  8030 maintenance_manager.cc:419] P 252f1baa290545ba8194ed1157e93dc2: Scheduling LogGCOp(507bc7fc24ec49d7958b870a11d5c0ad): free 20290830 bytes of WAL
I20260812 06:17:38.776396  7932 log_reader.cc:385] T 507bc7fc24ec49d7958b870a11d5c0ad: removed 2 log segments from log reader
I20260812 06:17:38.776443  7932 log.cc:1079] T 507bc7fc24ec49d7958b870a11d5c0ad P 252f1baa290545ba8194ed1157e93dc2: Deleting log segment in path: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453282085-7439-0/minicluster-data/ts-0-root/wals/507bc7fc24ec49d7958b870a11d5c0ad/wal-000000001 (ops 1-6)
I20260812 06:17:38.776482  7932 log.cc:1079] T 507bc7fc24ec49d7958b870a11d5c0ad P 252f1baa290545ba8194ed1157e93dc2: Deleting log segment in path: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453282085-7439-0/minicluster-data/ts-0-root/wals/507bc7fc24ec49d7958b870a11d5c0ad/wal-000000002 (ops 7-10)
I20260812 06:17:38.780004  7932 maintenance_manager.cc:643] P 252f1baa290545ba8194ed1157e93dc2: LogGCOp(507bc7fc24ec49d7958b870a11d5c0ad) complete. Timing: real 0.004s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:17:38.780360  8030 maintenance_manager.cc:419] P 252f1baa290545ba8194ed1157e93dc2: Scheduling UndoDeltaBlockGCOp(507bc7fc24ec49d7958b870a11d5c0ad): 20513814 bytes on disk
I20260812 06:17:38.780772  7932 maintenance_manager.cc:643] P 252f1baa290545ba8194ed1157e93dc2: UndoDeltaBlockGCOp(507bc7fc24ec49d7958b870a11d5c0ad) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":46,"lbm_reads_lt_1ms":4}
I20260812 06:17:38.781261  8030 maintenance_manager.cc:419] P 252f1baa290545ba8194ed1157e93dc2: Scheduling FlushDeltaMemStoresOp(507bc7fc24ec49d7958b870a11d5c0ad): perf score=2.188937
I20260812 06:17:38.803105  7932 maintenance_manager.cc:643] P 252f1baa290545ba8194ed1157e93dc2: FlushDeltaMemStoresOp(507bc7fc24ec49d7958b870a11d5c0ad) complete. Timing: real 0.022s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4020609,"delete_count":0,"lbm_write_time_us":4383,"lbm_writes_lt_1ms":101,"reinsert_count":0,"update_count":490}
I20260812 06:17:38.803503  8030 maintenance_manager.cc:419] P 252f1baa290545ba8194ed1157e93dc2: Scheduling FlushDeltaMemStoresOp(507bc7fc24ec49d7958b870a11d5c0ad): perf score=2.188937
I20260812 06:17:38.812558  7932 maintenance_manager.cc:643] P 252f1baa290545ba8194ed1157e93dc2: FlushDeltaMemStoresOp(507bc7fc24ec49d7958b870a11d5c0ad) complete. Timing: real 0.009s	user 0.003s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3166,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:38.812988  8030 maintenance_manager.cc:419] P 252f1baa290545ba8194ed1157e93dc2: Scheduling MajorDeltaCompactionOp(507bc7fc24ec49d7958b870a11d5c0ad): perf score=1.000000
I20260812 06:17:38.979785  7932 maintenance_manager.cc:643] P 252f1baa290545ba8194ed1157e93dc2: MajorDeltaCompactionOp(507bc7fc24ec49d7958b870a11d5c0ad) complete. Timing: real 0.167s	user 0.128s	sys 0.033s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815783,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":313,"lbm_read_time_us":13563,"lbm_reads_lt_1ms":569,"lbm_write_time_us":26550,"lbm_writes_lt_1ms":543,"mutex_wait_us":30,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3840,"thread_start_us":285,"threads_started":5,"update_count":2500}
I20260812 06:17:38.980294  8030 maintenance_manager.cc:419] P 252f1baa290545ba8194ed1157e93dc2: Scheduling FlushDeltaMemStoresOp(507bc7fc24ec49d7958b870a11d5c0ad): perf score=14.095187
I20260812 06:17:39.029740  7932 maintenance_manager.cc:643] P 252f1baa290545ba8194ed1157e93dc2: FlushDeltaMemStoresOp(507bc7fc24ec49d7958b870a11d5c0ad) complete. Timing: real 0.049s	user 0.028s	sys 0.020s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":21720,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:39.030287  8030 maintenance_manager.cc:419] P 252f1baa290545ba8194ed1157e93dc2: Scheduling FlushDeltaMemStoresOp(507bc7fc24ec49d7958b870a11d5c0ad): perf score=2.188937
I20260812 06:17:39.041347  7932 maintenance_manager.cc:643] P 252f1baa290545ba8194ed1157e93dc2: FlushDeltaMemStoresOp(507bc7fc24ec49d7958b870a11d5c0ad) complete. Timing: real 0.011s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3944,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:39.041795  8030 maintenance_manager.cc:419] P 252f1baa290545ba8194ed1157e93dc2: Scheduling MajorDeltaCompactionOp(507bc7fc24ec49d7958b870a11d5c0ad): perf score=1.000000
I20260812 06:17:39.204557  7932 maintenance_manager.cc:643] P 252f1baa290545ba8194ed1157e93dc2: MajorDeltaCompactionOp(507bc7fc24ec49d7958b870a11d5c0ad) complete. Timing: real 0.163s	user 0.113s	sys 0.033s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":589,"lbm_read_time_us":10781,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28974,"lbm_writes_lt_1ms":543,"mutex_wait_us":291,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5504,"update_count":2500}
I20260812 06:17:39.205298  8030 maintenance_manager.cc:419] P 252f1baa290545ba8194ed1157e93dc2: Scheduling FlushDeltaMemStoresOp(507bc7fc24ec49d7958b870a11d5c0ad): perf score=14.095187
I20260812 06:17:39.262428  7932 maintenance_manager.cc:643] P 252f1baa290545ba8194ed1157e93dc2: FlushDeltaMemStoresOp(507bc7fc24ec49d7958b870a11d5c0ad) complete. Timing: real 0.057s	user 0.029s	sys 0.013s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19104,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:39.262950  8030 maintenance_manager.cc:419] P 252f1baa290545ba8194ed1157e93dc2: Scheduling FlushDeltaMemStoresOp(507bc7fc24ec49d7958b870a11d5c0ad): perf score=2.188937
I20260812 06:17:39.273082  7932 maintenance_manager.cc:643] P 252f1baa290545ba8194ed1157e93dc2: FlushDeltaMemStoresOp(507bc7fc24ec49d7958b870a11d5c0ad) complete. Timing: real 0.010s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3587,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:39.273677  8030 maintenance_manager.cc:419] P 252f1baa290545ba8194ed1157e93dc2: Scheduling MajorDeltaCompactionOp(507bc7fc24ec49d7958b870a11d5c0ad): perf score=1.000000
I20260812 06:17:39.449671  7932 maintenance_manager.cc:643] P 252f1baa290545ba8194ed1157e93dc2: MajorDeltaCompactionOp(507bc7fc24ec49d7958b870a11d5c0ad) complete. Timing: real 0.176s	user 0.120s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":160,"lbm_read_time_us":11088,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29230,"lbm_writes_lt_1ms":543,"mutex_wait_us":27,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4608,"update_count":2500}
I20260812 06:17:39.450265  8030 maintenance_manager.cc:419] P 252f1baa290545ba8194ed1157e93dc2: Scheduling FlushDeltaMemStoresOp(507bc7fc24ec49d7958b870a11d5c0ad): perf score=14.095187
I20260812 06:17:39.492316  7932 maintenance_manager.cc:643] P 252f1baa290545ba8194ed1157e93dc2: FlushDeltaMemStoresOp(507bc7fc24ec49d7958b870a11d5c0ad) complete. Timing: real 0.042s	user 0.030s	sys 0.009s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18563,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:39.492765  8030 maintenance_manager.cc:419] P 252f1baa290545ba8194ed1157e93dc2: Scheduling MajorDeltaCompactionOp(507bc7fc24ec49d7958b870a11d5c0ad): perf score=1.000000
I20260812 06:17:39.637076  7932 maintenance_manager.cc:643] P 252f1baa290545ba8194ed1157e93dc2: MajorDeltaCompactionOp(507bc7fc24ec49d7958b870a11d5c0ad) complete. Timing: real 0.144s	user 0.102s	sys 0.040s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713152,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":621,"lbm_read_time_us":9695,"lbm_reads_lt_1ms":467,"lbm_write_time_us":21559,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:39.637660  8030 maintenance_manager.cc:419] P 252f1baa290545ba8194ed1157e93dc2: Scheduling FlushDeltaMemStoresOp(507bc7fc24ec49d7958b870a11d5c0ad): perf score=11.118625
I20260812 06:17:39.665769  7932 maintenance_manager.cc:643] P 252f1baa290545ba8194ed1157e93dc2: FlushDeltaMemStoresOp(507bc7fc24ec49d7958b870a11d5c0ad) complete. Timing: real 0.028s	user 0.011s	sys 0.016s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":11902,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:39.666420  8030 maintenance_manager.cc:419] P 252f1baa290545ba8194ed1157e93dc2: Scheduling FlushDeltaMemStoresOp(507bc7fc24ec49d7958b870a11d5c0ad): perf score=2.188937
I20260812 06:17:39.686115  7932 maintenance_manager.cc:643] P 252f1baa290545ba8194ed1157e93dc2: FlushDeltaMemStoresOp(507bc7fc24ec49d7958b870a11d5c0ad) complete. Timing: real 0.019s	user 0.009s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5901,"lbm_writes_lt_1ms":93,"mutex_wait_us":3,"reinsert_count":0,"update_count":450}
I20260812 06:17:39.686663  8030 maintenance_manager.cc:419] P 252f1baa290545ba8194ed1157e93dc2: Scheduling MajorDeltaCompactionOp(507bc7fc24ec49d7958b870a11d5c0ad): perf score=1.000000
I20260812 06:17:39.811333  7932 maintenance_manager.cc:643] P 252f1baa290545ba8194ed1157e93dc2: MajorDeltaCompactionOp(507bc7fc24ec49d7958b870a11d5c0ad) complete. Timing: real 0.124s	user 0.089s	sys 0.033s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713263,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":685,"lbm_read_time_us":7409,"lbm_reads_lt_1ms":464,"lbm_write_time_us":22172,"lbm_writes_lt_1ms":443,"mutex_wait_us":310,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12800,"update_count":2000}
I20260812 06:17:39.811905  8030 maintenance_manager.cc:419] P 252f1baa290545ba8194ed1157e93dc2: Scheduling FlushDeltaMemStoresOp(507bc7fc24ec49d7958b870a11d5c0ad): perf score=10.126437
I20260812 06:17:39.852906  7932 maintenance_manager.cc:643] P 252f1baa290545ba8194ed1157e93dc2: FlushDeltaMemStoresOp(507bc7fc24ec49d7958b870a11d5c0ad) complete. Timing: real 0.041s	user 0.023s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19881,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:17:39.853514  8030 maintenance_manager.cc:419] P 252f1baa290545ba8194ed1157e93dc2: Scheduling FlushDeltaMemStoresOp(507bc7fc24ec49d7958b870a11d5c0ad): perf score=2.188937
I20260812 06:17:39.878947  7932 maintenance_manager.cc:643] P 252f1baa290545ba8194ed1157e93dc2: FlushDeltaMemStoresOp(507bc7fc24ec49d7958b870a11d5c0ad) complete. Timing: real 0.025s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4793,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:39.879508  8030 maintenance_manager.cc:419] P 252f1baa290545ba8194ed1157e93dc2: Scheduling FlushDeltaMemStoresOp(507bc7fc24ec49d7958b870a11d5c0ad): perf score=2.188937
I20260812 06:17:39.889597  7932 maintenance_manager.cc:643] P 252f1baa290545ba8194ed1157e93dc2: FlushDeltaMemStoresOp(507bc7fc24ec49d7958b870a11d5c0ad) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3730,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:39.890130  8030 maintenance_manager.cc:419] P 252f1baa290545ba8194ed1157e93dc2: Scheduling FlushMRSOp(507bc7fc24ec49d7958b870a11d5c0ad): perf score=1.000000
I20260812 06:17:39.922363  7932 maintenance_manager.cc:643] P 252f1baa290545ba8194ed1157e93dc2: FlushMRSOp(507bc7fc24ec49d7958b870a11d5c0ad) complete. Timing: real 0.032s	user 0.031s	sys 0.000s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":54,"dirs.run_cpu_time_us":221,"dirs.run_wall_time_us":1074,"drs_written":1,"lbm_read_time_us":112,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2039,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:17:39.922991  8030 maintenance_manager.cc:419] P 252f1baa290545ba8194ed1157e93dc2: Scheduling LogGCOp(507bc7fc24ec49d7958b870a11d5c0ad): free 112692309 bytes of WAL
I20260812 06:17:39.923204  7932 log_reader.cc:385] T 507bc7fc24ec49d7958b870a11d5c0ad: removed 11 log segments from log reader
I20260812 06:17:39.923250  7932 log.cc:1079] T 507bc7fc24ec49d7958b870a11d5c0ad P 252f1baa290545ba8194ed1157e93dc2: Deleting log segment in path: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453282085-7439-0/minicluster-data/ts-0-root/wals/507bc7fc24ec49d7958b870a11d5c0ad/wal-000000003 (ops 11-15)
I20260812 06:17:39.923288  7932 log.cc:1079] T 507bc7fc24ec49d7958b870a11d5c0ad P 252f1baa290545ba8194ed1157e93dc2: Deleting log segment in path: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453282085-7439-0/minicluster-data/ts-0-root/wals/507bc7fc24ec49d7958b870a11d5c0ad/wal-000000004 (ops 16-20)
I20260812 06:17:39.923321  7932 log.cc:1079] T 507bc7fc24ec49d7958b870a11d5c0ad P 252f1baa290545ba8194ed1157e93dc2: Deleting log segment in path: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453282085-7439-0/minicluster-data/ts-0-root/wals/507bc7fc24ec49d7958b870a11d5c0ad/wal-000000005 (ops 21-25)
I20260812 06:17:39.923353  7932 log.cc:1079] T 507bc7fc24ec49d7958b870a11d5c0ad P 252f1baa290545ba8194ed1157e93dc2: Deleting log segment in path: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453282085-7439-0/minicluster-data/ts-0-root/wals/507bc7fc24ec49d7958b870a11d5c0ad/wal-000000006 (ops 26-30)
I20260812 06:17:39.923386  7932 log.cc:1079] T 507bc7fc24ec49d7958b870a11d5c0ad P 252f1baa290545ba8194ed1157e93dc2: Deleting log segment in path: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453282085-7439-0/minicluster-data/ts-0-root/wals/507bc7fc24ec49d7958b870a11d5c0ad/wal-000000007 (ops 31-35)
I20260812 06:17:39.923418  7932 log.cc:1079] T 507bc7fc24ec49d7958b870a11d5c0ad P 252f1baa290545ba8194ed1157e93dc2: Deleting log segment in path: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453282085-7439-0/minicluster-data/ts-0-root/wals/507bc7fc24ec49d7958b870a11d5c0ad/wal-000000008 (ops 36-40)
I20260812 06:17:39.923450  7932 log.cc:1079] T 507bc7fc24ec49d7958b870a11d5c0ad P 252f1baa290545ba8194ed1157e93dc2: Deleting log segment in path: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453282085-7439-0/minicluster-data/ts-0-root/wals/507bc7fc24ec49d7958b870a11d5c0ad/wal-000000009 (ops 41-45)
I20260812 06:17:39.923481  7932 log.cc:1079] T 507bc7fc24ec49d7958b870a11d5c0ad P 252f1baa290545ba8194ed1157e93dc2: Deleting log segment in path: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453282085-7439-0/minicluster-data/ts-0-root/wals/507bc7fc24ec49d7958b870a11d5c0ad/wal-000000010 (ops 46-50)
I20260812 06:17:39.923512  7932 log.cc:1079] T 507bc7fc24ec49d7958b870a11d5c0ad P 252f1baa290545ba8194ed1157e93dc2: Deleting log segment in path: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453282085-7439-0/minicluster-data/ts-0-root/wals/507bc7fc24ec49d7958b870a11d5c0ad/wal-000000011 (ops 51-55)
I20260812 06:17:39.923544  7932 log.cc:1079] T 507bc7fc24ec49d7958b870a11d5c0ad P 252f1baa290545ba8194ed1157e93dc2: Deleting log segment in path: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453282085-7439-0/minicluster-data/ts-0-root/wals/507bc7fc24ec49d7958b870a11d5c0ad/wal-000000012 (ops 56-60)
I20260812 06:17:39.923576  7932 log.cc:1079] T 507bc7fc24ec49d7958b870a11d5c0ad P 252f1baa290545ba8194ed1157e93dc2: Deleting log segment in path: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453282085-7439-0/minicluster-data/ts-0-root/wals/507bc7fc24ec49d7958b870a11d5c0ad/wal-000000013 (ops 61-65)
I20260812 06:17:39.944684  7932 maintenance_manager.cc:643] P 252f1baa290545ba8194ed1157e93dc2: LogGCOp(507bc7fc24ec49d7958b870a11d5c0ad) complete. Timing: real 0.022s	user 0.000s	sys 0.018s Metrics: {}
I20260812 06:17:39.945118  8030 maintenance_manager.cc:419] P 252f1baa290545ba8194ed1157e93dc2: Scheduling FlushDeltaMemStoresOp(507bc7fc24ec49d7958b870a11d5c0ad): perf score=3.181125
I20260812 06:17:39.961215  7932 maintenance_manager.cc:643] P 252f1baa290545ba8194ed1157e93dc2: FlushDeltaMemStoresOp(507bc7fc24ec49d7958b870a11d5c0ad) complete. Timing: real 0.016s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4512905,"delete_count":0,"lbm_write_time_us":3952,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:39.961683  8030 maintenance_manager.cc:419] P 252f1baa290545ba8194ed1157e93dc2: Scheduling UndoDeltaBlockGCOp(507bc7fc24ec49d7958b870a11d5c0ad): 447 bytes on disk
I20260812 06:17:39.962113  7932 maintenance_manager.cc:643] P 252f1baa290545ba8194ed1157e93dc2: UndoDeltaBlockGCOp(507bc7fc24ec49d7958b870a11d5c0ad) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":70,"lbm_reads_lt_1ms":4}
I20260812 06:17:39.962582  8030 maintenance_manager.cc:419] P 252f1baa290545ba8194ed1157e93dc2: Scheduling FlushDeltaMemStoresOp(507bc7fc24ec49d7958b870a11d5c0ad): perf score=2.188937
I20260812 06:17:39.976828  7932 maintenance_manager.cc:643] P 252f1baa290545ba8194ed1157e93dc2: FlushDeltaMemStoresOp(507bc7fc24ec49d7958b870a11d5c0ad) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4895,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:39.977562  8030 maintenance_manager.cc:419] P 252f1baa290545ba8194ed1157e93dc2: Scheduling MajorDeltaCompactionOp(507bc7fc24ec49d7958b870a11d5c0ad): perf score=1.000000
I20260812 06:17:40.178229  7932 maintenance_manager.cc:643] P 252f1baa290545ba8194ed1157e93dc2: MajorDeltaCompactionOp(507bc7fc24ec49d7958b870a11d5c0ad) complete. Timing: real 0.200s	user 0.136s	sys 0.057s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":33020856,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":1193,"lbm_read_time_us":13452,"lbm_reads_lt_1ms":775,"lbm_write_time_us":32525,"lbm_writes_lt_1ms":743,"mutex_wait_us":516,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":86,"threads_started":1,"update_count":3500}
I20260812 06:17:40.179188  8030 maintenance_manager.cc:419] P 252f1baa290545ba8194ed1157e93dc2: Scheduling FlushDeltaMemStoresOp(507bc7fc24ec49d7958b870a11d5c0ad): perf score=15.087375
I20260812 06:17:40.225849  7932 maintenance_manager.cc:643] P 252f1baa290545ba8194ed1157e93dc2: FlushDeltaMemStoresOp(507bc7fc24ec49d7958b870a11d5c0ad) complete. Timing: real 0.046s	user 0.022s	sys 0.023s Metrics: {"bytes_written":16820142,"delete_count":0,"lbm_write_time_us":16675,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:17:40.226670  8030 maintenance_manager.cc:419] P 252f1baa290545ba8194ed1157e93dc2: Scheduling FlushDeltaMemStoresOp(507bc7fc24ec49d7958b870a11d5c0ad): perf score=2.188937
I20260812 06:17:40.240043  7932 maintenance_manager.cc:643] P 252f1baa290545ba8194ed1157e93dc2: FlushDeltaMemStoresOp(507bc7fc24ec49d7958b870a11d5c0ad) complete. Timing: real 0.013s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3785,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:40.240463  8030 maintenance_manager.cc:419] P 252f1baa290545ba8194ed1157e93dc2: Scheduling FlushDeltaMemStoresOp(507bc7fc24ec49d7958b870a11d5c0ad): perf score=2.188937
I20260812 06:17:40.249444  7932 maintenance_manager.cc:643] P 252f1baa290545ba8194ed1157e93dc2: FlushDeltaMemStoresOp(507bc7fc24ec49d7958b870a11d5c0ad) complete. Timing: real 0.009s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3289,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:40.249817  8030 maintenance_manager.cc:419] P 252f1baa290545ba8194ed1157e93dc2: Scheduling MajorDeltaCompactionOp(507bc7fc24ec49d7958b870a11d5c0ad): perf score=1.000000
I20260812 06:17:40.447381  7932 maintenance_manager.cc:643] P 252f1baa290545ba8194ed1157e93dc2: MajorDeltaCompactionOp(507bc7fc24ec49d7958b870a11d5c0ad) complete. Timing: real 0.197s	user 0.132s	sys 0.065s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918201,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":895,"lbm_read_time_us":14512,"lbm_reads_lt_1ms":673,"lbm_write_time_us":32624,"lbm_writes_lt_1ms":643,"mutex_wait_us":258,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":4864,"update_count":3000}
I20260812 06:17:40.448009  8030 maintenance_manager.cc:419] P 252f1baa290545ba8194ed1157e93dc2: Scheduling FlushDeltaMemStoresOp(507bc7fc24ec49d7958b870a11d5c0ad): perf score=14.095187
I20260812 06:17:40.495887  7932 maintenance_manager.cc:643] P 252f1baa290545ba8194ed1157e93dc2: FlushDeltaMemStoresOp(507bc7fc24ec49d7958b870a11d5c0ad) complete. Timing: real 0.048s	user 0.016s	sys 0.028s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21270,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:40.496374  8030 maintenance_manager.cc:419] P 252f1baa290545ba8194ed1157e93dc2: Scheduling FlushDeltaMemStoresOp(507bc7fc24ec49d7958b870a11d5c0ad): perf score=2.188937
I20260812 06:17:40.507509  7932 maintenance_manager.cc:643] P 252f1baa290545ba8194ed1157e93dc2: FlushDeltaMemStoresOp(507bc7fc24ec49d7958b870a11d5c0ad) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4219,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:40.507928  8030 maintenance_manager.cc:419] P 252f1baa290545ba8194ed1157e93dc2: Scheduling MajorDeltaCompactionOp(507bc7fc24ec49d7958b870a11d5c0ad): perf score=1.000000
I20260812 06:17:40.676666  7932 maintenance_manager.cc:643] P 252f1baa290545ba8194ed1157e93dc2: MajorDeltaCompactionOp(507bc7fc24ec49d7958b870a11d5c0ad) complete. Timing: real 0.169s	user 0.116s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":611,"lbm_read_time_us":12034,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28423,"lbm_writes_lt_1ms":543,"mutex_wait_us":63,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5248,"update_count":2500}
I20260812 06:17:40.677186  8030 maintenance_manager.cc:419] P 252f1baa290545ba8194ed1157e93dc2: Scheduling FlushDeltaMemStoresOp(507bc7fc24ec49d7958b870a11d5c0ad): perf score=14.095187
I20260812 06:17:40.731629  7932 maintenance_manager.cc:643] P 252f1baa290545ba8194ed1157e93dc2: FlushDeltaMemStoresOp(507bc7fc24ec49d7958b870a11d5c0ad) complete. Timing: real 0.054s	user 0.022s	sys 0.023s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":17418,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:40.732303  8030 maintenance_manager.cc:419] P 252f1baa290545ba8194ed1157e93dc2: Scheduling FlushDeltaMemStoresOp(507bc7fc24ec49d7958b870a11d5c0ad): perf score=2.188937
I20260812 06:17:40.749444  7932 maintenance_manager.cc:643] P 252f1baa290545ba8194ed1157e93dc2: FlushDeltaMemStoresOp(507bc7fc24ec49d7958b870a11d5c0ad) complete. Timing: real 0.017s	user 0.005s	sys 0.012s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6722,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:40.749967  8030 maintenance_manager.cc:419] P 252f1baa290545ba8194ed1157e93dc2: Scheduling MajorDeltaCompactionOp(507bc7fc24ec49d7958b870a11d5c0ad): perf score=1.000000
I20260812 06:17:40.917513  7932 maintenance_manager.cc:643] P 252f1baa290545ba8194ed1157e93dc2: MajorDeltaCompactionOp(507bc7fc24ec49d7958b870a11d5c0ad) complete. Timing: real 0.167s	user 0.105s	sys 0.050s 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":608,"lbm_read_time_us":11664,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25400,"lbm_writes_lt_1ms":543,"mutex_wait_us":86,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4992,"update_count":2500}
I20260812 06:17:40.918042  8030 maintenance_manager.cc:419] P 252f1baa290545ba8194ed1157e93dc2: Scheduling FlushDeltaMemStoresOp(507bc7fc24ec49d7958b870a11d5c0ad): perf score=14.095187
I20260812 06:17:40.972831  7932 maintenance_manager.cc:643] P 252f1baa290545ba8194ed1157e93dc2: FlushDeltaMemStoresOp(507bc7fc24ec49d7958b870a11d5c0ad) complete. Timing: real 0.055s	user 0.016s	sys 0.028s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":17173,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:40.973337  8030 maintenance_manager.cc:419] P 252f1baa290545ba8194ed1157e93dc2: Scheduling FlushDeltaMemStoresOp(507bc7fc24ec49d7958b870a11d5c0ad): perf score=2.188937
I20260812 06:17:40.983489  7932 maintenance_manager.cc:643] P 252f1baa290545ba8194ed1157e93dc2: FlushDeltaMemStoresOp(507bc7fc24ec49d7958b870a11d5c0ad) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3877,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:40.984005  8030 maintenance_manager.cc:419] P 252f1baa290545ba8194ed1157e93dc2: Scheduling MajorDeltaCompactionOp(507bc7fc24ec49d7958b870a11d5c0ad): perf score=1.000000
I20260812 06:17:41.159336  7932 maintenance_manager.cc:643] P 252f1baa290545ba8194ed1157e93dc2: MajorDeltaCompactionOp(507bc7fc24ec49d7958b870a11d5c0ad) complete. Timing: real 0.175s	user 0.123s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1084,"lbm_read_time_us":12560,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28357,"lbm_writes_lt_1ms":543,"mutex_wait_us":289,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12928,"update_count":2500}
I20260812 06:17:41.159883  8030 maintenance_manager.cc:419] P 252f1baa290545ba8194ed1157e93dc2: Scheduling FlushDeltaMemStoresOp(507bc7fc24ec49d7958b870a11d5c0ad): perf score=11.118625
I20260812 06:17:41.195297  7932 maintenance_manager.cc:643] P 252f1baa290545ba8194ed1157e93dc2: FlushDeltaMemStoresOp(507bc7fc24ec49d7958b870a11d5c0ad) complete. Timing: real 0.035s	user 0.013s	sys 0.020s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15088,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:41.195845  8030 maintenance_manager.cc:419] P 252f1baa290545ba8194ed1157e93dc2: Scheduling FlushDeltaMemStoresOp(507bc7fc24ec49d7958b870a11d5c0ad): perf score=2.188937
I20260812 06:17:41.211076  7932 maintenance_manager.cc:643] P 252f1baa290545ba8194ed1157e93dc2: FlushDeltaMemStoresOp(507bc7fc24ec49d7958b870a11d5c0ad) complete. Timing: real 0.015s	user 0.004s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5217,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:41.211628  8030 maintenance_manager.cc:419] P 252f1baa290545ba8194ed1157e93dc2: Scheduling FlushMRSOp(507bc7fc24ec49d7958b870a11d5c0ad): perf score=1.000000
I20260812 06:17:41.248543  7932 maintenance_manager.cc:643] P 252f1baa290545ba8194ed1157e93dc2: FlushMRSOp(507bc7fc24ec49d7958b870a11d5c0ad) complete. Timing: real 0.037s	user 0.018s	sys 0.005s Metrics: {"bytes_written":1152514,"cfile_init":1,"dirs.queue_time_us":64,"dirs.run_cpu_time_us":238,"dirs.run_wall_time_us":1173,"drs_written":1,"lbm_read_time_us":46,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1406,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:17:41.249243  8030 maintenance_manager.cc:419] P 252f1baa290545ba8194ed1157e93dc2: Scheduling UndoDeltaBlockGCOp(507bc7fc24ec49d7958b870a11d5c0ad): 448 bytes on disk
I20260812 06:17:41.249606  7932 maintenance_manager.cc:643] P 252f1baa290545ba8194ed1157e93dc2: UndoDeltaBlockGCOp(507bc7fc24ec49d7958b870a11d5c0ad) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":45,"lbm_reads_lt_1ms":4}
I20260812 06:17:41.250213  8030 maintenance_manager.cc:419] P 252f1baa290545ba8194ed1157e93dc2: Scheduling FlushDeltaMemStoresOp(507bc7fc24ec49d7958b870a11d5c0ad): perf score=3.181125
I20260812 06:17:41.269152  7932 maintenance_manager.cc:643] P 252f1baa290545ba8194ed1157e93dc2: FlushDeltaMemStoresOp(507bc7fc24ec49d7958b870a11d5c0ad) complete. Timing: real 0.019s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4003,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:41.269629  8030 maintenance_manager.cc:419] P 252f1baa290545ba8194ed1157e93dc2: Scheduling LogGCOp(507bc7fc24ec49d7958b870a11d5c0ad): free 120553433 bytes of WAL
I20260812 06:17:41.269836  7932 log_reader.cc:385] T 507bc7fc24ec49d7958b870a11d5c0ad: removed 12 log segments from log reader
I20260812 06:17:41.269887  7932 log.cc:1079] T 507bc7fc24ec49d7958b870a11d5c0ad P 252f1baa290545ba8194ed1157e93dc2: Deleting log segment in path: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453282085-7439-0/minicluster-data/ts-0-root/wals/507bc7fc24ec49d7958b870a11d5c0ad/wal-000000014 (ops 66-70)
I20260812 06:17:41.269932  7932 log.cc:1079] T 507bc7fc24ec49d7958b870a11d5c0ad P 252f1baa290545ba8194ed1157e93dc2: Deleting log segment in path: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453282085-7439-0/minicluster-data/ts-0-root/wals/507bc7fc24ec49d7958b870a11d5c0ad/wal-000000015 (ops 71-74)
I20260812 06:17:41.269961  7932 log.cc:1079] T 507bc7fc24ec49d7958b870a11d5c0ad P 252f1baa290545ba8194ed1157e93dc2: Deleting log segment in path: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453282085-7439-0/minicluster-data/ts-0-root/wals/507bc7fc24ec49d7958b870a11d5c0ad/wal-000000016 (ops 75-79)
I20260812 06:17:41.269989  7932 log.cc:1079] T 507bc7fc24ec49d7958b870a11d5c0ad P 252f1baa290545ba8194ed1157e93dc2: Deleting log segment in path: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453282085-7439-0/minicluster-data/ts-0-root/wals/507bc7fc24ec49d7958b870a11d5c0ad/wal-000000017 (ops 80-84)
I20260812 06:17:41.270021  7932 log.cc:1079] T 507bc7fc24ec49d7958b870a11d5c0ad P 252f1baa290545ba8194ed1157e93dc2: Deleting log segment in path: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453282085-7439-0/minicluster-data/ts-0-root/wals/507bc7fc24ec49d7958b870a11d5c0ad/wal-000000018 (ops 85-88)
I20260812 06:17:41.270051  7932 log.cc:1079] T 507bc7fc24ec49d7958b870a11d5c0ad P 252f1baa290545ba8194ed1157e93dc2: Deleting log segment in path: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453282085-7439-0/minicluster-data/ts-0-root/wals/507bc7fc24ec49d7958b870a11d5c0ad/wal-000000019 (ops 89-93)
I20260812 06:17:41.270076  7932 log.cc:1079] T 507bc7fc24ec49d7958b870a11d5c0ad P 252f1baa290545ba8194ed1157e93dc2: Deleting log segment in path: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453282085-7439-0/minicluster-data/ts-0-root/wals/507bc7fc24ec49d7958b870a11d5c0ad/wal-000000020 (ops 94-98)
I20260812 06:17:41.270100  7932 log.cc:1079] T 507bc7fc24ec49d7958b870a11d5c0ad P 252f1baa290545ba8194ed1157e93dc2: Deleting log segment in path: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453282085-7439-0/minicluster-data/ts-0-root/wals/507bc7fc24ec49d7958b870a11d5c0ad/wal-000000021 (ops 99-103)
I20260812 06:17:41.270129  7932 log.cc:1079] T 507bc7fc24ec49d7958b870a11d5c0ad P 252f1baa290545ba8194ed1157e93dc2: Deleting log segment in path: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453282085-7439-0/minicluster-data/ts-0-root/wals/507bc7fc24ec49d7958b870a11d5c0ad/wal-000000022 (ops 104-108)
I20260812 06:17:41.270153  7932 log.cc:1079] T 507bc7fc24ec49d7958b870a11d5c0ad P 252f1baa290545ba8194ed1157e93dc2: Deleting log segment in path: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453282085-7439-0/minicluster-data/ts-0-root/wals/507bc7fc24ec49d7958b870a11d5c0ad/wal-000000023 (ops 109-113)
I20260812 06:17:41.270183  7932 log.cc:1079] T 507bc7fc24ec49d7958b870a11d5c0ad P 252f1baa290545ba8194ed1157e93dc2: Deleting log segment in path: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453282085-7439-0/minicluster-data/ts-0-root/wals/507bc7fc24ec49d7958b870a11d5c0ad/wal-000000024 (ops 114-118)
I20260812 06:17:41.270212  7932 log.cc:1079] T 507bc7fc24ec49d7958b870a11d5c0ad P 252f1baa290545ba8194ed1157e93dc2: Deleting log segment in path: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453282085-7439-0/minicluster-data/ts-0-root/wals/507bc7fc24ec49d7958b870a11d5c0ad/wal-000000025 (ops 119-123)
I20260812 06:17:41.297118  7932 maintenance_manager.cc:643] P 252f1baa290545ba8194ed1157e93dc2: LogGCOp(507bc7fc24ec49d7958b870a11d5c0ad) complete. Timing: real 0.027s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:17:41.297574  8030 maintenance_manager.cc:419] P 252f1baa290545ba8194ed1157e93dc2: Scheduling FlushDeltaMemStoresOp(507bc7fc24ec49d7958b870a11d5c0ad): perf score=2.188937
I20260812 06:17:41.316007  7932 maintenance_manager.cc:643] P 252f1baa290545ba8194ed1157e93dc2: FlushDeltaMemStoresOp(507bc7fc24ec49d7958b870a11d5c0ad) complete. Timing: real 0.018s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4158,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:41.316512  8030 maintenance_manager.cc:419] P 252f1baa290545ba8194ed1157e93dc2: Scheduling FlushDeltaMemStoresOp(507bc7fc24ec49d7958b870a11d5c0ad): perf score=2.188937
I20260812 06:17:41.329483  7932 maintenance_manager.cc:643] P 252f1baa290545ba8194ed1157e93dc2: FlushDeltaMemStoresOp(507bc7fc24ec49d7958b870a11d5c0ad) complete. Timing: real 0.013s	user 0.005s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4825,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:41.329959  8030 maintenance_manager.cc:419] P 252f1baa290545ba8194ed1157e93dc2: Scheduling MajorDeltaCompactionOp(507bc7fc24ec49d7958b870a11d5c0ad): perf score=1.000000
I20260812 06:17:41.556394  7932 maintenance_manager.cc:643] P 252f1baa290545ba8194ed1157e93dc2: MajorDeltaCompactionOp(507bc7fc24ec49d7958b870a11d5c0ad) complete. Timing: real 0.226s	user 0.131s	sys 0.083s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":33020846,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":2798,"lbm_read_time_us":14820,"lbm_reads_lt_1ms":775,"lbm_write_time_us":35260,"lbm_writes_lt_1ms":743,"mutex_wait_us":2599,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":17664,"thread_start_us":79,"threads_started":1,"update_count":3500}
I20260812 06:17:41.556985  8030 maintenance_manager.cc:419] P 252f1baa290545ba8194ed1157e93dc2: Scheduling FlushDeltaMemStoresOp(507bc7fc24ec49d7958b870a11d5c0ad): perf score=18.063937
I20260812 06:17:41.620600  7932 maintenance_manager.cc:643] P 252f1baa290545ba8194ed1157e93dc2: FlushDeltaMemStoresOp(507bc7fc24ec49d7958b870a11d5c0ad) complete. Timing: real 0.063s	user 0.029s	sys 0.017s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":22002,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:41.621192  8030 maintenance_manager.cc:419] P 252f1baa290545ba8194ed1157e93dc2: Scheduling FlushDeltaMemStoresOp(507bc7fc24ec49d7958b870a11d5c0ad): perf score=2.188937
I20260812 06:17:41.638288  7932 maintenance_manager.cc:643] P 252f1baa290545ba8194ed1157e93dc2: FlushDeltaMemStoresOp(507bc7fc24ec49d7958b870a11d5c0ad) complete. Timing: real 0.017s	user 0.011s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6484,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:41.638914  8030 maintenance_manager.cc:419] P 252f1baa290545ba8194ed1157e93dc2: Scheduling MajorDeltaCompactionOp(507bc7fc24ec49d7958b870a11d5c0ad): perf score=1.000000
I20260812 06:17:41.850986  7932 maintenance_manager.cc:643] P 252f1baa290545ba8194ed1157e93dc2: MajorDeltaCompactionOp(507bc7fc24ec49d7958b870a11d5c0ad) complete. Timing: real 0.212s	user 0.123s	sys 0.079s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918098,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":651,"lbm_read_time_us":14726,"lbm_reads_lt_1ms":672,"lbm_write_time_us":35736,"lbm_writes_lt_1ms":643,"mutex_wait_us":324,"peak_mem_usage":75542472,"reinsert_count":0,"update_count":3000}
I20260812 06:17:41.851655  8030 maintenance_manager.cc:419] P 252f1baa290545ba8194ed1157e93dc2: Scheduling FlushDeltaMemStoresOp(507bc7fc24ec49d7958b870a11d5c0ad): perf score=18.063937
I20260812 06:17:41.914551  7932 maintenance_manager.cc:643] P 252f1baa290545ba8194ed1157e93dc2: FlushDeltaMemStoresOp(507bc7fc24ec49d7958b870a11d5c0ad) complete. Timing: real 0.063s	user 0.025s	sys 0.036s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":26834,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:41.915077  8030 maintenance_manager.cc:419] P 252f1baa290545ba8194ed1157e93dc2: Scheduling FlushDeltaMemStoresOp(507bc7fc24ec49d7958b870a11d5c0ad): perf score=2.188937
I20260812 06:17:41.928010  7932 maintenance_manager.cc:643] P 252f1baa290545ba8194ed1157e93dc2: FlushDeltaMemStoresOp(507bc7fc24ec49d7958b870a11d5c0ad) complete. Timing: real 0.013s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4944,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:41.928498  8030 maintenance_manager.cc:419] P 252f1baa290545ba8194ed1157e93dc2: Scheduling MajorDeltaCompactionOp(507bc7fc24ec49d7958b870a11d5c0ad): perf score=1.000000
I20260812 06:17:42.137272  7932 maintenance_manager.cc:643] P 252f1baa290545ba8194ed1157e93dc2: MajorDeltaCompactionOp(507bc7fc24ec49d7958b870a11d5c0ad) complete. Timing: real 0.209s	user 0.138s	sys 0.061s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918097,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":3759,"lbm_read_time_us":12665,"lbm_reads_lt_1ms":672,"lbm_write_time_us":36092,"lbm_writes_lt_1ms":643,"mutex_wait_us":3408,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2560,"update_count":3000}
I20260812 06:17:42.138445  8030 maintenance_manager.cc:419] P 252f1baa290545ba8194ed1157e93dc2: Scheduling FlushDeltaMemStoresOp(507bc7fc24ec49d7958b870a11d5c0ad): perf score=18.063937
I20260812 06:17:42.195012  7932 maintenance_manager.cc:643] P 252f1baa290545ba8194ed1157e93dc2: FlushDeltaMemStoresOp(507bc7fc24ec49d7958b870a11d5c0ad) complete. Timing: real 0.056s	user 0.030s	sys 0.017s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":21918,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:42.195537  8030 maintenance_manager.cc:419] P 252f1baa290545ba8194ed1157e93dc2: Scheduling FlushDeltaMemStoresOp(507bc7fc24ec49d7958b870a11d5c0ad): perf score=2.188937
I20260812 06:17:42.205731  7932 maintenance_manager.cc:643] P 252f1baa290545ba8194ed1157e93dc2: FlushDeltaMemStoresOp(507bc7fc24ec49d7958b870a11d5c0ad) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3670,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:42.206331  8030 maintenance_manager.cc:419] P 252f1baa290545ba8194ed1157e93dc2: Scheduling MajorDeltaCompactionOp(507bc7fc24ec49d7958b870a11d5c0ad): perf score=1.000000
I20260812 06:17:42.399313  7932 maintenance_manager.cc:643] P 252f1baa290545ba8194ed1157e93dc2: MajorDeltaCompactionOp(507bc7fc24ec49d7958b870a11d5c0ad) complete. Timing: real 0.193s	user 0.098s	sys 0.090s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918099,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1728,"lbm_read_time_us":13188,"lbm_reads_lt_1ms":672,"lbm_write_time_us":33414,"lbm_writes_lt_1ms":643,"mutex_wait_us":348,"peak_mem_usage":75542472,"reinsert_count":0,"update_count":3000}
I20260812 06:17:42.399816  8030 maintenance_manager.cc:419] P 252f1baa290545ba8194ed1157e93dc2: Scheduling FlushDeltaMemStoresOp(507bc7fc24ec49d7958b870a11d5c0ad): perf score=15.087375
I20260812 06:17:42.451696  7932 maintenance_manager.cc:643] P 252f1baa290545ba8194ed1157e93dc2: FlushDeltaMemStoresOp(507bc7fc24ec49d7958b870a11d5c0ad) complete. Timing: real 0.052s	user 0.032s	sys 0.013s Metrics: {"bytes_written":16820141,"delete_count":0,"lbm_write_time_us":21630,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:17:42.452251  8030 maintenance_manager.cc:419] P 252f1baa290545ba8194ed1157e93dc2: Scheduling FlushDeltaMemStoresOp(507bc7fc24ec49d7958b870a11d5c0ad): perf score=2.188937
I20260812 06:17:42.463881  7932 maintenance_manager.cc:643] P 252f1baa290545ba8194ed1157e93dc2: FlushDeltaMemStoresOp(507bc7fc24ec49d7958b870a11d5c0ad) complete. Timing: real 0.011s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3812,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:42.464322  8030 maintenance_manager.cc:419] P 252f1baa290545ba8194ed1157e93dc2: Scheduling FlushDeltaMemStoresOp(507bc7fc24ec49d7958b870a11d5c0ad): perf score=2.188937
I20260812 06:17:42.473639  7932 maintenance_manager.cc:643] P 252f1baa290545ba8194ed1157e93dc2: FlushDeltaMemStoresOp(507bc7fc24ec49d7958b870a11d5c0ad) complete. Timing: real 0.009s	user 0.005s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3340,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:42.474112  8030 maintenance_manager.cc:419] P 252f1baa290545ba8194ed1157e93dc2: Scheduling MajorDeltaCompactionOp(507bc7fc24ec49d7958b870a11d5c0ad): perf score=1.000000
I20260812 06:17:42.689924  7932 maintenance_manager.cc:643] P 252f1baa290545ba8194ed1157e93dc2: MajorDeltaCompactionOp(507bc7fc24ec49d7958b870a11d5c0ad) complete. Timing: real 0.216s	user 0.163s	sys 0.052s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918200,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":306,"lbm_read_time_us":14470,"lbm_reads_lt_1ms":673,"lbm_write_time_us":40319,"lbm_writes_lt_1ms":643,"mutex_wait_us":63,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":9472,"update_count":3000}
I20260812 06:17:42.690481  8030 maintenance_manager.cc:419] P 252f1baa290545ba8194ed1157e93dc2: Scheduling FlushDeltaMemStoresOp(507bc7fc24ec49d7958b870a11d5c0ad): perf score=14.095187
I20260812 06:17:42.733429  7932 maintenance_manager.cc:643] P 252f1baa290545ba8194ed1157e93dc2: FlushDeltaMemStoresOp(507bc7fc24ec49d7958b870a11d5c0ad) complete. Timing: real 0.043s	user 0.019s	sys 0.023s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":17979,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:42.734086  8030 maintenance_manager.cc:419] P 252f1baa290545ba8194ed1157e93dc2: Scheduling FlushDeltaMemStoresOp(507bc7fc24ec49d7958b870a11d5c0ad): perf score=2.188937
I20260812 06:17:42.756541  7932 maintenance_manager.cc:643] P 252f1baa290545ba8194ed1157e93dc2: FlushDeltaMemStoresOp(507bc7fc24ec49d7958b870a11d5c0ad) complete. Timing: real 0.022s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5099,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:42.757059  8030 maintenance_manager.cc:419] P 252f1baa290545ba8194ed1157e93dc2: Scheduling FlushDeltaMemStoresOp(507bc7fc24ec49d7958b870a11d5c0ad): perf score=2.188937
I20260812 06:17:42.771687  7932 maintenance_manager.cc:643] P 252f1baa290545ba8194ed1157e93dc2: FlushDeltaMemStoresOp(507bc7fc24ec49d7958b870a11d5c0ad) complete. Timing: real 0.014s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5401,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:42.772218  8030 maintenance_manager.cc:419] P 252f1baa290545ba8194ed1157e93dc2: Scheduling FlushMRSOp(507bc7fc24ec49d7958b870a11d5c0ad): perf score=1.000000
I20260812 06:17:42.802755  7932 maintenance_manager.cc:643] P 252f1baa290545ba8194ed1157e93dc2: FlushMRSOp(507bc7fc24ec49d7958b870a11d5c0ad) complete. Timing: real 0.030s	user 0.020s	sys 0.008s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":62,"dirs.run_cpu_time_us":222,"dirs.run_wall_time_us":1218,"drs_written":1,"lbm_read_time_us":42,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1613,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:17:42.803442  8030 maintenance_manager.cc:419] P 252f1baa290545ba8194ed1157e93dc2: Scheduling LogGCOp(507bc7fc24ec49d7958b870a11d5c0ad): free 133024572 bytes of WAL
I20260812 06:17:42.803673  7932 log_reader.cc:385] T 507bc7fc24ec49d7958b870a11d5c0ad: removed 13 log segments from log reader
I20260812 06:17:42.803735  7932 log.cc:1079] T 507bc7fc24ec49d7958b870a11d5c0ad P 252f1baa290545ba8194ed1157e93dc2: Deleting log segment in path: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453282085-7439-0/minicluster-data/ts-0-root/wals/507bc7fc24ec49d7958b870a11d5c0ad/wal-000000026 (ops 124-128)
I20260812 06:17:42.803777  7932 log.cc:1079] T 507bc7fc24ec49d7958b870a11d5c0ad P 252f1baa290545ba8194ed1157e93dc2: Deleting log segment in path: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453282085-7439-0/minicluster-data/ts-0-root/wals/507bc7fc24ec49d7958b870a11d5c0ad/wal-000000027 (ops 129-133)
I20260812 06:17:42.803804  7932 log.cc:1079] T 507bc7fc24ec49d7958b870a11d5c0ad P 252f1baa290545ba8194ed1157e93dc2: Deleting log segment in path: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453282085-7439-0/minicluster-data/ts-0-root/wals/507bc7fc24ec49d7958b870a11d5c0ad/wal-000000028 (ops 134-138)
I20260812 06:17:42.803836  7932 log.cc:1079] T 507bc7fc24ec49d7958b870a11d5c0ad P 252f1baa290545ba8194ed1157e93dc2: Deleting log segment in path: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453282085-7439-0/minicluster-data/ts-0-root/wals/507bc7fc24ec49d7958b870a11d5c0ad/wal-000000029 (ops 139-143)
I20260812 06:17:42.803865  7932 log.cc:1079] T 507bc7fc24ec49d7958b870a11d5c0ad P 252f1baa290545ba8194ed1157e93dc2: Deleting log segment in path: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453282085-7439-0/minicluster-data/ts-0-root/wals/507bc7fc24ec49d7958b870a11d5c0ad/wal-000000030 (ops 144-148)
I20260812 06:17:42.803892  7932 log.cc:1079] T 507bc7fc24ec49d7958b870a11d5c0ad P 252f1baa290545ba8194ed1157e93dc2: Deleting log segment in path: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453282085-7439-0/minicluster-data/ts-0-root/wals/507bc7fc24ec49d7958b870a11d5c0ad/wal-000000031 (ops 149-153)
I20260812 06:17:42.803920  7932 log.cc:1079] T 507bc7fc24ec49d7958b870a11d5c0ad P 252f1baa290545ba8194ed1157e93dc2: Deleting log segment in path: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453282085-7439-0/minicluster-data/ts-0-root/wals/507bc7fc24ec49d7958b870a11d5c0ad/wal-000000032 (ops 154-158)
I20260812 06:17:42.803951  7932 log.cc:1079] T 507bc7fc24ec49d7958b870a11d5c0ad P 252f1baa290545ba8194ed1157e93dc2: Deleting log segment in path: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453282085-7439-0/minicluster-data/ts-0-root/wals/507bc7fc24ec49d7958b870a11d5c0ad/wal-000000033 (ops 159-163)
I20260812 06:17:42.803982  7932 log.cc:1079] T 507bc7fc24ec49d7958b870a11d5c0ad P 252f1baa290545ba8194ed1157e93dc2: Deleting log segment in path: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453282085-7439-0/minicluster-data/ts-0-root/wals/507bc7fc24ec49d7958b870a11d5c0ad/wal-000000034 (ops 164-168)
I20260812 06:17:42.804009  7932 log.cc:1079] T 507bc7fc24ec49d7958b870a11d5c0ad P 252f1baa290545ba8194ed1157e93dc2: Deleting log segment in path: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453282085-7439-0/minicluster-data/ts-0-root/wals/507bc7fc24ec49d7958b870a11d5c0ad/wal-000000035 (ops 169-172)
I20260812 06:17:42.804034  7932 log.cc:1079] T 507bc7fc24ec49d7958b870a11d5c0ad P 252f1baa290545ba8194ed1157e93dc2: Deleting log segment in path: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453282085-7439-0/minicluster-data/ts-0-root/wals/507bc7fc24ec49d7958b870a11d5c0ad/wal-000000036 (ops 173-177)
I20260812 06:17:42.804062  7932 log.cc:1079] T 507bc7fc24ec49d7958b870a11d5c0ad P 252f1baa290545ba8194ed1157e93dc2: Deleting log segment in path: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453282085-7439-0/minicluster-data/ts-0-root/wals/507bc7fc24ec49d7958b870a11d5c0ad/wal-000000037 (ops 178-182)
I20260812 06:17:42.804092  7932 log.cc:1079] T 507bc7fc24ec49d7958b870a11d5c0ad P 252f1baa290545ba8194ed1157e93dc2: Deleting log segment in path: /tmp/dist-test-taskWmgMAV/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515453282085-7439-0/minicluster-data/ts-0-root/wals/507bc7fc24ec49d7958b870a11d5c0ad/wal-000000038 (ops 183-187)
I20260812 06:17:42.832235  7932 maintenance_manager.cc:643] P 252f1baa290545ba8194ed1157e93dc2: LogGCOp(507bc7fc24ec49d7958b870a11d5c0ad) complete. Timing: real 0.029s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:17:42.832612  8030 maintenance_manager.cc:419] P 252f1baa290545ba8194ed1157e93dc2: Scheduling FlushDeltaMemStoresOp(507bc7fc24ec49d7958b870a11d5c0ad): perf score=3.181125
I20260812 06:17:42.848258  7932 maintenance_manager.cc:643] P 252f1baa290545ba8194ed1157e93dc2: FlushDeltaMemStoresOp(507bc7fc24ec49d7958b870a11d5c0ad) complete. Timing: real 0.015s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4232,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:42.848699  8030 maintenance_manager.cc:419] P 252f1baa290545ba8194ed1157e93dc2: Scheduling FlushDeltaMemStoresOp(507bc7fc24ec49d7958b870a11d5c0ad): perf score=2.188937
I20260812 06:17:42.857797  7932 maintenance_manager.cc:643] P 252f1baa290545ba8194ed1157e93dc2: FlushDeltaMemStoresOp(507bc7fc24ec49d7958b870a11d5c0ad) complete. Timing: real 0.009s	user 0.007s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3326,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:42.858269  8030 maintenance_manager.cc:419] P 252f1baa290545ba8194ed1157e93dc2: Scheduling MajorDeltaCompactionOp(507bc7fc24ec49d7958b870a11d5c0ad): perf score=1.000000
I20260812 06:17:43.079257  7439 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.624s	user 1.599s	sys 0.231s
I20260812 06:17:43.083653  7932 maintenance_manager.cc:643] P 252f1baa290545ba8194ed1157e93dc2: MajorDeltaCompactionOp(507bc7fc24ec49d7958b870a11d5c0ad) complete. Timing: real 0.225s	user 0.170s	sys 0.053s Metrics: {"cfile_cache_miss":835,"cfile_cache_miss_bytes":37123268,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"lbm_read_time_us":16974,"lbm_reads_lt_1ms":875,"lbm_write_time_us":41298,"lbm_writes_lt_1ms":843,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":5120,"update_count":4000}
I20260812 06:17:43.084103  8030 maintenance_manager.cc:419] P 252f1baa290545ba8194ed1157e93dc2: Scheduling UndoDeltaBlockGCOp(507bc7fc24ec49d7958b870a11d5c0ad): 491 bytes on disk
I20260812 06:17:43.084472  7932 maintenance_manager.cc:643] P 252f1baa290545ba8194ed1157e93dc2: UndoDeltaBlockGCOp(507bc7fc24ec49d7958b870a11d5c0ad) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4}
I20260812 06:17:43.084988  8030 maintenance_manager.cc:419] P 252f1baa290545ba8194ed1157e93dc2: Scheduling FlushDeltaMemStoresOp(507bc7fc24ec49d7958b870a11d5c0ad): perf score=18.063937
I20260812 06:17:43.122965  7932 maintenance_manager.cc:643] P 252f1baa290545ba8194ed1157e93dc2: FlushDeltaMemStoresOp(507bc7fc24ec49d7958b870a11d5c0ad) complete. Timing: real 0.038s	user 0.025s	sys 0.012s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":17693,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:43.123423  8030 maintenance_manager.cc:419] P 252f1baa290545ba8194ed1157e93dc2: Scheduling MajorDeltaCompactionOp(507bc7fc24ec49d7958b870a11d5c0ad): perf score=1.000000
I20260812 06:17:43.155491  7439 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.076s	user 0.001s	sys 0.000s
I20260812 06:17:43.155987  7439 tablet_server.cc:179] TabletServer@127.7.67.193:0 shutting down...
I20260812 06:17:43.244287  7932 maintenance_manager.cc:643] P 252f1baa290545ba8194ed1157e93dc2: MajorDeltaCompactionOp(507bc7fc24ec49d7958b870a11d5c0ad) complete. Timing: real 0.121s	user 0.092s	sys 0.028s Metrics: {"cfile_cache_miss":531,"cfile_cache_miss_bytes":24815566,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":1022,"lbm_read_time_us":8396,"lbm_reads_lt_1ms":567,"lbm_write_time_us":25288,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":542,"mutex_wait_us":285,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2500}
I20260812 06:17:43.244848  7439 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:43.245087  7439 tablet_replica.cc:333] T 507bc7fc24ec49d7958b870a11d5c0ad P 252f1baa290545ba8194ed1157e93dc2: stopping tablet replica
I20260812 06:17:43.245217  7439 raft_consensus.cc:2243] T 507bc7fc24ec49d7958b870a11d5c0ad P 252f1baa290545ba8194ed1157e93dc2 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:43.245378  7439 raft_consensus.cc:2272] T 507bc7fc24ec49d7958b870a11d5c0ad P 252f1baa290545ba8194ed1157e93dc2 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:43.249693  7439 tablet_server.cc:196] TabletServer@127.7.67.193:0 shutdown complete.
I20260812 06:17:43.316056  7439 master.cc:562] Master@127.7.67.254:41275 shutting down...
I20260812 06:17:43.319290  7439 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 1fe80eb201474722b54f4aeac2a34b24 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:43.319465  7439 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 1fe80eb201474722b54f4aeac2a34b24 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:43.319537  7439 tablet_replica.cc:333] T 00000000000000000000000000000000 P 1fe80eb201474722b54f4aeac2a34b24: stopping tablet replica
I20260812 06:17:43.331861  7439 master.cc:584] Master@127.7.67.254:41275 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5127 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10117 ms total)

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