[==========] 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:16:41.688505  7331 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.7.40.254:45451
I20260812 06:16:41.689532  7331 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:16:41.690164  7331 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:41.696743  7337 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:16:41.696839  7331 server_base.cc:1061] running on GCE node
W20260812 06:16:41.696743  7338 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:16:41.697036  7340 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:16:41.697605  7331 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:41.697721  7331 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:16:41.697768  7331 hybrid_clock.cc:648] HybridClock initialized: now 1786515401697765 us; error 0 us; skew 500 ppm
I20260812 06:16:41.699657  7331 webserver.cc:533] Webserver started at http://127.7.40.254:35349/ using document root <none> and password file <none>
I20260812 06:16:41.700222  7331 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:41.700284  7331 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:41.700574  7331 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:41.702286  7331 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515401677830-7331-0/minicluster-data/master-0-root/instance:
uuid: "faf5aa209b034b51896eb96012733019"
format_stamp: "Formatted at 2026-08-12 06:16:41 on dist-test-slave-69rg"
I20260812 06:16:41.705760  7331 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:16:41.707872  7345 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:16:41.708828  7331 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:16:41.708931  7331 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515401677830-7331-0/minicluster-data/master-0-root
uuid: "faf5aa209b034b51896eb96012733019"
format_stamp: "Formatted at 2026-08-12 06:16:41 on dist-test-slave-69rg"
I20260812 06:16:41.709053  7331 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515401677830-7331-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515401677830-7331-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515401677830-7331-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:16:41.719146  7331 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:41.719805  7331 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:16:41.719993  7331 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:41.727826  7403 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.7.40.254:45451 every 8 connection(s)
I20260812 06:16:41.727824  7331 rpc_server.cc:307] RPC server started. Bound to: 127.7.40.254:45451
I20260812 06:16:41.730191  7404 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:16:41.735592  7404 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P faf5aa209b034b51896eb96012733019: Bootstrap starting.
I20260812 06:16:41.738133  7404 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P faf5aa209b034b51896eb96012733019: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:41.739073  7404 log.cc:826] T 00000000000000000000000000000000 P faf5aa209b034b51896eb96012733019: Log is configured to *not* fsync() on all Append() calls
I20260812 06:16:41.740720  7404 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P faf5aa209b034b51896eb96012733019: No bootstrap required, opened a new log
I20260812 06:16:41.743937  7404 raft_consensus.cc:359] T 00000000000000000000000000000000 P faf5aa209b034b51896eb96012733019 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "faf5aa209b034b51896eb96012733019" member_type: VOTER }
I20260812 06:16:41.744215  7404 raft_consensus.cc:385] T 00000000000000000000000000000000 P faf5aa209b034b51896eb96012733019 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:41.744333  7404 raft_consensus.cc:740] T 00000000000000000000000000000000 P faf5aa209b034b51896eb96012733019 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: faf5aa209b034b51896eb96012733019, State: Initialized, Role: FOLLOWER
I20260812 06:16:41.744935  7404 consensus_queue.cc:260] T 00000000000000000000000000000000 P faf5aa209b034b51896eb96012733019 [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: "faf5aa209b034b51896eb96012733019" member_type: VOTER }
I20260812 06:16:41.745133  7404 raft_consensus.cc:399] T 00000000000000000000000000000000 P faf5aa209b034b51896eb96012733019 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:41.745208  7404 raft_consensus.cc:493] T 00000000000000000000000000000000 P faf5aa209b034b51896eb96012733019 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:41.745344  7404 raft_consensus.cc:3060] T 00000000000000000000000000000000 P faf5aa209b034b51896eb96012733019 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:41.746294  7404 raft_consensus.cc:515] T 00000000000000000000000000000000 P faf5aa209b034b51896eb96012733019 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "faf5aa209b034b51896eb96012733019" member_type: VOTER }
I20260812 06:16:41.746731  7404 leader_election.cc:304] T 00000000000000000000000000000000 P faf5aa209b034b51896eb96012733019 [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: faf5aa209b034b51896eb96012733019; no voters: 
I20260812 06:16:41.747061  7404 leader_election.cc:290] T 00000000000000000000000000000000 P faf5aa209b034b51896eb96012733019 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:41.747254  7407 raft_consensus.cc:2804] T 00000000000000000000000000000000 P faf5aa209b034b51896eb96012733019 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:41.747588  7407 raft_consensus.cc:697] T 00000000000000000000000000000000 P faf5aa209b034b51896eb96012733019 [term 1 LEADER]: Becoming Leader. State: Replica: faf5aa209b034b51896eb96012733019, State: Running, Role: LEADER
I20260812 06:16:41.748050  7407 consensus_queue.cc:237] T 00000000000000000000000000000000 P faf5aa209b034b51896eb96012733019 [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: "faf5aa209b034b51896eb96012733019" member_type: VOTER }
I20260812 06:16:41.748172  7404 sys_catalog.cc:565] T 00000000000000000000000000000000 P faf5aa209b034b51896eb96012733019 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:16:41.749989  7409 sys_catalog.cc:455] T 00000000000000000000000000000000 P faf5aa209b034b51896eb96012733019 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "faf5aa209b034b51896eb96012733019" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "faf5aa209b034b51896eb96012733019" member_type: VOTER } }
I20260812 06:16:41.750017  7410 sys_catalog.cc:455] T 00000000000000000000000000000000 P faf5aa209b034b51896eb96012733019 [sys.catalog]: SysCatalogTable state changed. Reason: New leader faf5aa209b034b51896eb96012733019. Latest consensus state: current_term: 1 leader_uuid: "faf5aa209b034b51896eb96012733019" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "faf5aa209b034b51896eb96012733019" member_type: VOTER } }
I20260812 06:16:41.750115  7409 sys_catalog.cc:458] T 00000000000000000000000000000000 P faf5aa209b034b51896eb96012733019 [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:41.750115  7410 sys_catalog.cc:458] T 00000000000000000000000000000000 P faf5aa209b034b51896eb96012733019 [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:41.750479  7421 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:16:41.750675  7331 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:16:41.752722  7421 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:16:41.757175  7421 catalog_manager.cc:1383] Generated new cluster ID: cf351cfe547d40dfbec1a817e4598e21
I20260812 06:16:41.757241  7421 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:16:41.767176  7421 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:16:41.768069  7421 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:16:41.781040  7421 catalog_manager.cc:6092] T 00000000000000000000000000000000 P faf5aa209b034b51896eb96012733019: Generated new TSK 0
I20260812 06:16:41.781692  7421 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:16:41.783215  7331 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:41.786175  7431 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:16:41.786221  7435 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:16:41.786348  7331 server_base.cc:1061] running on GCE node
W20260812 06:16:41.786175  7430 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:16:41.786681  7331 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:41.786725  7331 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:16:41.786741  7331 hybrid_clock.cc:648] HybridClock initialized: now 1786515401786740 us; error 0 us; skew 500 ppm
I20260812 06:16:41.787689  7331 webserver.cc:533] Webserver started at http://127.7.40.193:33363/ using document root <none> and password file <none>
I20260812 06:16:41.787891  7331 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:41.787945  7331 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:41.788044  7331 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:41.788435  7331 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515401677830-7331-0/minicluster-data/ts-0-root/instance:
uuid: "7477e4b95a4b40798320ef6f1e760237"
format_stamp: "Formatted at 2026-08-12 06:16:41 on dist-test-slave-69rg"
I20260812 06:16:41.790011  7331 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:16:41.791050  7440 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:16:41.791322  7331 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:16:41.791404  7331 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515401677830-7331-0/minicluster-data/ts-0-root
uuid: "7477e4b95a4b40798320ef6f1e760237"
format_stamp: "Formatted at 2026-08-12 06:16:41 on dist-test-slave-69rg"
I20260812 06:16:41.791500  7331 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515401677830-7331-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515401677830-7331-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515401677830-7331-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:16:41.802325  7331 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:41.802788  7331 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:41.803310  7331 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:16:41.804177  7331 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:16:41.804229  7331 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:41.804293  7331 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:16:41.804333  7331 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:41.811080  7331 rpc_server.cc:307] RPC server started. Bound to: 127.7.40.193:43919
I20260812 06:16:41.811112  7517 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.7.40.193:43919 every 8 connection(s)
I20260812 06:16:41.821907  7518 heartbeater.cc:344] Connected to a master server at 127.7.40.254:45451
I20260812 06:16:41.822166  7518 heartbeater.cc:461] Registering TS with master...
I20260812 06:16:41.822659  7518 heartbeater.cc:507] Master 127.7.40.254:45451 requested a full tablet report, sending...
I20260812 06:16:41.824257  7362 ts_manager.cc:194] Registered new tserver with Master: 7477e4b95a4b40798320ef6f1e760237 (127.7.40.193:43919)
I20260812 06:16:41.824393  7331 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.012682651s
I20260812 06:16:41.825788  7362 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:56454
I20260812 06:16:41.834405  7362 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:56464:
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:16:41.850045  7477 tablet_service.cc:1511] Processing CreateTablet for tablet eb52a41a60b044c99169cb1e7c23222d (DEFAULT_TABLE table=heavy-update-compaction-test [id=7e15ac83602a4421b397ca4c96cc55d4]), partition=
I20260812 06:16:41.850517  7477 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet eb52a41a60b044c99169cb1e7c23222d. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:16:41.852984  7531 tablet_bootstrap.cc:492] T eb52a41a60b044c99169cb1e7c23222d P 7477e4b95a4b40798320ef6f1e760237: Bootstrap starting.
I20260812 06:16:41.853991  7531 tablet_bootstrap.cc:654] T eb52a41a60b044c99169cb1e7c23222d P 7477e4b95a4b40798320ef6f1e760237: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:41.855096  7531 tablet_bootstrap.cc:492] T eb52a41a60b044c99169cb1e7c23222d P 7477e4b95a4b40798320ef6f1e760237: No bootstrap required, opened a new log
I20260812 06:16:41.855209  7531 ts_tablet_manager.cc:1403] T eb52a41a60b044c99169cb1e7c23222d P 7477e4b95a4b40798320ef6f1e760237: Time spent bootstrapping tablet: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:16:41.855701  7531 raft_consensus.cc:359] T eb52a41a60b044c99169cb1e7c23222d P 7477e4b95a4b40798320ef6f1e760237 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7477e4b95a4b40798320ef6f1e760237" member_type: VOTER last_known_addr { host: "127.7.40.193" port: 43919 } }
I20260812 06:16:41.855803  7531 raft_consensus.cc:385] T eb52a41a60b044c99169cb1e7c23222d P 7477e4b95a4b40798320ef6f1e760237 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:41.855861  7531 raft_consensus.cc:740] T eb52a41a60b044c99169cb1e7c23222d P 7477e4b95a4b40798320ef6f1e760237 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 7477e4b95a4b40798320ef6f1e760237, State: Initialized, Role: FOLLOWER
I20260812 06:16:41.856038  7531 consensus_queue.cc:260] T eb52a41a60b044c99169cb1e7c23222d P 7477e4b95a4b40798320ef6f1e760237 [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: "7477e4b95a4b40798320ef6f1e760237" member_type: VOTER last_known_addr { host: "127.7.40.193" port: 43919 } }
I20260812 06:16:41.856160  7531 raft_consensus.cc:399] T eb52a41a60b044c99169cb1e7c23222d P 7477e4b95a4b40798320ef6f1e760237 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:41.856262  7531 raft_consensus.cc:493] T eb52a41a60b044c99169cb1e7c23222d P 7477e4b95a4b40798320ef6f1e760237 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:41.856344  7531 raft_consensus.cc:3060] T eb52a41a60b044c99169cb1e7c23222d P 7477e4b95a4b40798320ef6f1e760237 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:41.857156  7531 raft_consensus.cc:515] T eb52a41a60b044c99169cb1e7c23222d P 7477e4b95a4b40798320ef6f1e760237 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7477e4b95a4b40798320ef6f1e760237" member_type: VOTER last_known_addr { host: "127.7.40.193" port: 43919 } }
I20260812 06:16:41.857323  7531 leader_election.cc:304] T eb52a41a60b044c99169cb1e7c23222d P 7477e4b95a4b40798320ef6f1e760237 [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: 7477e4b95a4b40798320ef6f1e760237; no voters: 
I20260812 06:16:41.857561  7531 leader_election.cc:290] T eb52a41a60b044c99169cb1e7c23222d P 7477e4b95a4b40798320ef6f1e760237 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:41.857654  7533 raft_consensus.cc:2804] T eb52a41a60b044c99169cb1e7c23222d P 7477e4b95a4b40798320ef6f1e760237 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:41.857870  7533 raft_consensus.cc:697] T eb52a41a60b044c99169cb1e7c23222d P 7477e4b95a4b40798320ef6f1e760237 [term 1 LEADER]: Becoming Leader. State: Replica: 7477e4b95a4b40798320ef6f1e760237, State: Running, Role: LEADER
I20260812 06:16:41.857975  7531 ts_tablet_manager.cc:1434] T eb52a41a60b044c99169cb1e7c23222d P 7477e4b95a4b40798320ef6f1e760237: Time spent starting tablet: real 0.003s	user 0.000s	sys 0.003s
I20260812 06:16:41.858093  7533 consensus_queue.cc:237] T eb52a41a60b044c99169cb1e7c23222d P 7477e4b95a4b40798320ef6f1e760237 [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: "7477e4b95a4b40798320ef6f1e760237" member_type: VOTER last_known_addr { host: "127.7.40.193" port: 43919 } }
I20260812 06:16:41.858261  7518 heartbeater.cc:499] Master 127.7.40.254:45451 was elected leader, sending a full tablet report...
I20260812 06:16:41.860721  7362 catalog_manager.cc:5719] T eb52a41a60b044c99169cb1e7c23222d P 7477e4b95a4b40798320ef6f1e760237 reported cstate change: term changed from 0 to 1, leader changed from <none> to 7477e4b95a4b40798320ef6f1e760237 (127.7.40.193). New cstate: current_term: 1 leader_uuid: "7477e4b95a4b40798320ef6f1e760237" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7477e4b95a4b40798320ef6f1e760237" member_type: VOTER last_known_addr { host: "127.7.40.193" port: 43919 } health_report { overall_health: HEALTHY } } }
I20260812 06:16:41.934652  7331 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.065s	user 0.028s	sys 0.004s
I20260812 06:16:42.062441  7519 maintenance_manager.cc:419] P 7477e4b95a4b40798320ef6f1e760237: Scheduling FlushMRSOp(eb52a41a60b044c99169cb1e7c23222d): perf score=15.086190
I20260812 06:16:42.235287  7446 maintenance_manager.cc:643] P 7477e4b95a4b40798320ef6f1e760237: FlushMRSOp(eb52a41a60b044c99169cb1e7c23222d) complete. Timing: real 0.172s	user 0.118s	sys 0.045s Metrics: {"bytes_written":12717736,"cfile_init":1,"compiler_manager_pool.queue_time_us":618,"delete_count":0,"dirs.queue_time_us":85,"dirs.run_cpu_time_us":246,"dirs.run_wall_time_us":1064,"drs_written":1,"lbm_read_time_us":82,"lbm_reads_lt_1ms":4,"lbm_write_time_us":39286,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":666,"peak_mem_usage":0,"reinsert_count":0,"rows_written":103,"thread_start_us":120,"threads_started":1,"update_count":1550}
I20260812 06:16:42.236948  7519 maintenance_manager.cc:419] P 7477e4b95a4b40798320ef6f1e760237: Scheduling LogGCOp(eb52a41a60b044c99169cb1e7c23222d): free 11976772 bytes of WAL
I20260812 06:16:42.237286  7446 log_reader.cc:385] T eb52a41a60b044c99169cb1e7c23222d: removed 1 log segments from log reader
I20260812 06:16:42.237414  7446 log.cc:1079] T eb52a41a60b044c99169cb1e7c23222d P 7477e4b95a4b40798320ef6f1e760237: Deleting log segment in path: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515401677830-7331-0/minicluster-data/ts-0-root/wals/eb52a41a60b044c99169cb1e7c23222d/wal-000000001 (ops 1-6)
I20260812 06:16:42.240942  7446 maintenance_manager.cc:643] P 7477e4b95a4b40798320ef6f1e760237: LogGCOp(eb52a41a60b044c99169cb1e7c23222d) complete. Timing: real 0.004s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:16:42.241490  7519 maintenance_manager.cc:419] P 7477e4b95a4b40798320ef6f1e760237: Scheduling UndoDeltaBlockGCOp(eb52a41a60b044c99169cb1e7c23222d): 12308959 bytes on disk
I20260812 06:16:42.242709  7446 maintenance_manager.cc:643] P 7477e4b95a4b40798320ef6f1e760237: UndoDeltaBlockGCOp(eb52a41a60b044c99169cb1e7c23222d) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":89,"lbm_reads_lt_1ms":4}
I20260812 06:16:42.243292  7519 maintenance_manager.cc:419] P 7477e4b95a4b40798320ef6f1e760237: Scheduling FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d): perf score=2.188937
I20260812 06:16:42.265687  7446 maintenance_manager.cc:643] P 7477e4b95a4b40798320ef6f1e760237: FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d) complete. Timing: real 0.022s	user 0.017s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7662,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:42.266215  7519 maintenance_manager.cc:419] P 7477e4b95a4b40798320ef6f1e760237: Scheduling FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d): perf score=2.188937
I20260812 06:16:42.279573  7446 maintenance_manager.cc:643] P 7477e4b95a4b40798320ef6f1e760237: FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d) complete. Timing: real 0.013s	user 0.003s	sys 0.009s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5112,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:42.280113  7519 maintenance_manager.cc:419] P 7477e4b95a4b40798320ef6f1e760237: Scheduling MajorDeltaCompactionOp(eb52a41a60b044c99169cb1e7c23222d): perf score=1.000000
I20260812 06:16:42.429066  7446 maintenance_manager.cc:643] P 7477e4b95a4b40798320ef6f1e760237: MajorDeltaCompactionOp(eb52a41a60b044c99169cb1e7c23222d) complete. Timing: real 0.149s	user 0.124s	sys 0.024s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24733835,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":609,"lbm_read_time_us":9986,"lbm_reads_lt_1ms":569,"lbm_write_time_us":27680,"lbm_writes_lt_1ms":543,"mutex_wait_us":23,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12928,"thread_start_us":351,"threads_started":5,"update_count":2500}
I20260812 06:16:42.429705  7519 maintenance_manager.cc:419] P 7477e4b95a4b40798320ef6f1e760237: Scheduling FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d): perf score=10.126437
I20260812 06:16:42.467258  7446 maintenance_manager.cc:643] P 7477e4b95a4b40798320ef6f1e760237: FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d) complete. Timing: real 0.037s	user 0.031s	sys 0.004s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15960,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:42.467895  7519 maintenance_manager.cc:419] P 7477e4b95a4b40798320ef6f1e760237: Scheduling FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d): perf score=2.188937
I20260812 06:16:42.479048  7446 maintenance_manager.cc:643] P 7477e4b95a4b40798320ef6f1e760237: FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4211,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:42.479501  7519 maintenance_manager.cc:419] P 7477e4b95a4b40798320ef6f1e760237: Scheduling MajorDeltaCompactionOp(eb52a41a60b044c99169cb1e7c23222d): perf score=1.000000
I20260812 06:16:42.608498  7446 maintenance_manager.cc:643] P 7477e4b95a4b40798320ef6f1e760237: MajorDeltaCompactionOp(eb52a41a60b044c99169cb1e7c23222d) complete. Timing: real 0.129s	user 0.096s	sys 0.033s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":244,"lbm_read_time_us":9845,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25689,"lbm_writes_lt_1ms":443,"mutex_wait_us":40,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11136,"update_count":2000}
I20260812 06:16:42.609246  7519 maintenance_manager.cc:419] P 7477e4b95a4b40798320ef6f1e760237: Scheduling FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d): perf score=10.126437
I20260812 06:16:42.659128  7446 maintenance_manager.cc:643] P 7477e4b95a4b40798320ef6f1e760237: FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d) complete. Timing: real 0.050s	user 0.024s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17975,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:42.659669  7519 maintenance_manager.cc:419] P 7477e4b95a4b40798320ef6f1e760237: Scheduling FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d): perf score=2.188937
I20260812 06:16:42.672669  7446 maintenance_manager.cc:643] P 7477e4b95a4b40798320ef6f1e760237: FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d) complete. Timing: real 0.013s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4622,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:42.673280  7519 maintenance_manager.cc:419] P 7477e4b95a4b40798320ef6f1e760237: Scheduling MajorDeltaCompactionOp(eb52a41a60b044c99169cb1e7c23222d): perf score=1.000000
I20260812 06:16:42.797171  7446 maintenance_manager.cc:643] P 7477e4b95a4b40798320ef6f1e760237: MajorDeltaCompactionOp(eb52a41a60b044c99169cb1e7c23222d) complete. Timing: real 0.124s	user 0.104s	sys 0.019s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":624,"lbm_read_time_us":8151,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23495,"lbm_writes_lt_1ms":443,"mutex_wait_us":62,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:16:42.797962  7519 maintenance_manager.cc:419] P 7477e4b95a4b40798320ef6f1e760237: Scheduling FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d): perf score=10.126437
I20260812 06:16:42.844617  7446 maintenance_manager.cc:643] P 7477e4b95a4b40798320ef6f1e760237: FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d) complete. Timing: real 0.046s	user 0.023s	sys 0.020s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":16136,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:42.845341  7519 maintenance_manager.cc:419] P 7477e4b95a4b40798320ef6f1e760237: Scheduling FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d): perf score=2.188937
I20260812 06:16:42.862596  7446 maintenance_manager.cc:643] P 7477e4b95a4b40798320ef6f1e760237: FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d) complete. Timing: real 0.017s	user 0.013s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6543,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:42.863190  7519 maintenance_manager.cc:419] P 7477e4b95a4b40798320ef6f1e760237: Scheduling MajorDeltaCompactionOp(eb52a41a60b044c99169cb1e7c23222d): perf score=1.000000
I20260812 06:16:43.007092  7446 maintenance_manager.cc:643] P 7477e4b95a4b40798320ef6f1e760237: MajorDeltaCompactionOp(eb52a41a60b044c99169cb1e7c23222d) complete. Timing: real 0.144s	user 0.099s	sys 0.044s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631313,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":685,"lbm_read_time_us":10053,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23840,"lbm_writes_lt_1ms":443,"mutex_wait_us":211,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11008,"update_count":2000}
I20260812 06:16:43.007601  7519 maintenance_manager.cc:419] P 7477e4b95a4b40798320ef6f1e760237: Scheduling FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d): perf score=10.126437
I20260812 06:16:43.048504  7446 maintenance_manager.cc:643] P 7477e4b95a4b40798320ef6f1e760237: FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d) complete. Timing: real 0.041s	user 0.018s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15999,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:43.049043  7519 maintenance_manager.cc:419] P 7477e4b95a4b40798320ef6f1e760237: Scheduling FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d): perf score=2.188937
I20260812 06:16:43.060168  7446 maintenance_manager.cc:643] P 7477e4b95a4b40798320ef6f1e760237: FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4135,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:43.060794  7519 maintenance_manager.cc:419] P 7477e4b95a4b40798320ef6f1e760237: Scheduling MajorDeltaCompactionOp(eb52a41a60b044c99169cb1e7c23222d): perf score=1.000000
I20260812 06:16:43.188562  7446 maintenance_manager.cc:643] P 7477e4b95a4b40798320ef6f1e760237: MajorDeltaCompactionOp(eb52a41a60b044c99169cb1e7c23222d) complete. Timing: real 0.128s	user 0.109s	sys 0.016s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":596,"lbm_read_time_us":8832,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24157,"lbm_writes_lt_1ms":443,"mutex_wait_us":83,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:16:43.189350  7519 maintenance_manager.cc:419] P 7477e4b95a4b40798320ef6f1e760237: Scheduling FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d): perf score=10.126437
I20260812 06:16:43.225088  7446 maintenance_manager.cc:643] P 7477e4b95a4b40798320ef6f1e760237: FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d) complete. Timing: real 0.036s	user 0.026s	sys 0.003s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13979,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:43.225725  7519 maintenance_manager.cc:419] P 7477e4b95a4b40798320ef6f1e760237: Scheduling FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d): perf score=2.188937
I20260812 06:16:43.236509  7446 maintenance_manager.cc:643] P 7477e4b95a4b40798320ef6f1e760237: FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4152,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:43.237181  7519 maintenance_manager.cc:419] P 7477e4b95a4b40798320ef6f1e760237: Scheduling MajorDeltaCompactionOp(eb52a41a60b044c99169cb1e7c23222d): perf score=1.000000
I20260812 06:16:43.363514  7446 maintenance_manager.cc:643] P 7477e4b95a4b40798320ef6f1e760237: MajorDeltaCompactionOp(eb52a41a60b044c99169cb1e7c23222d) complete. Timing: real 0.126s	user 0.106s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":381,"lbm_read_time_us":9767,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23468,"lbm_writes_lt_1ms":443,"mutex_wait_us":24,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":31360,"update_count":2000}
I20260812 06:16:43.364017  7519 maintenance_manager.cc:419] P 7477e4b95a4b40798320ef6f1e760237: Scheduling FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d): perf score=10.126437
I20260812 06:16:43.409018  7446 maintenance_manager.cc:643] P 7477e4b95a4b40798320ef6f1e760237: FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d) complete. Timing: real 0.045s	user 0.020s	sys 0.016s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":17121,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:43.409471  7519 maintenance_manager.cc:419] P 7477e4b95a4b40798320ef6f1e760237: Scheduling FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d): perf score=2.188937
I20260812 06:16:43.419927  7446 maintenance_manager.cc:643] P 7477e4b95a4b40798320ef6f1e760237: FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4027,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:43.420607  7519 maintenance_manager.cc:419] P 7477e4b95a4b40798320ef6f1e760237: Scheduling FlushMRSOp(eb52a41a60b044c99169cb1e7c23222d): perf score=1.000000
I20260812 06:16:43.451151  7446 maintenance_manager.cc:643] P 7477e4b95a4b40798320ef6f1e760237: FlushMRSOp(eb52a41a60b044c99169cb1e7c23222d) complete. Timing: real 0.030s	user 0.025s	sys 0.004s Metrics: {"bytes_written":1193504,"cfile_init":1,"dirs.queue_time_us":71,"dirs.run_cpu_time_us":261,"dirs.run_wall_time_us":1373,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1825,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29,"spinlock_wait_cycles":768}
I20260812 06:16:43.452081  7519 maintenance_manager.cc:419] P 7477e4b95a4b40798320ef6f1e760237: Scheduling LogGCOp(eb52a41a60b044c99169cb1e7c23222d): free 121006412 bytes of WAL
I20260812 06:16:43.452373  7446 log_reader.cc:385] T eb52a41a60b044c99169cb1e7c23222d: removed 12 log segments from log reader
I20260812 06:16:43.452435  7446 log.cc:1079] T eb52a41a60b044c99169cb1e7c23222d P 7477e4b95a4b40798320ef6f1e760237: Deleting log segment in path: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515401677830-7331-0/minicluster-data/ts-0-root/wals/eb52a41a60b044c99169cb1e7c23222d/wal-000000002 (ops 7-11)
I20260812 06:16:43.452477  7446 log.cc:1079] T eb52a41a60b044c99169cb1e7c23222d P 7477e4b95a4b40798320ef6f1e760237: Deleting log segment in path: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515401677830-7331-0/minicluster-data/ts-0-root/wals/eb52a41a60b044c99169cb1e7c23222d/wal-000000003 (ops 12-16)
I20260812 06:16:43.452512  7446 log.cc:1079] T eb52a41a60b044c99169cb1e7c23222d P 7477e4b95a4b40798320ef6f1e760237: Deleting log segment in path: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515401677830-7331-0/minicluster-data/ts-0-root/wals/eb52a41a60b044c99169cb1e7c23222d/wal-000000004 (ops 17-21)
I20260812 06:16:43.452538  7446 log.cc:1079] T eb52a41a60b044c99169cb1e7c23222d P 7477e4b95a4b40798320ef6f1e760237: Deleting log segment in path: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515401677830-7331-0/minicluster-data/ts-0-root/wals/eb52a41a60b044c99169cb1e7c23222d/wal-000000005 (ops 22-26)
I20260812 06:16:43.452567  7446 log.cc:1079] T eb52a41a60b044c99169cb1e7c23222d P 7477e4b95a4b40798320ef6f1e760237: Deleting log segment in path: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515401677830-7331-0/minicluster-data/ts-0-root/wals/eb52a41a60b044c99169cb1e7c23222d/wal-000000006 (ops 27-30)
I20260812 06:16:43.452596  7446 log.cc:1079] T eb52a41a60b044c99169cb1e7c23222d P 7477e4b95a4b40798320ef6f1e760237: Deleting log segment in path: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515401677830-7331-0/minicluster-data/ts-0-root/wals/eb52a41a60b044c99169cb1e7c23222d/wal-000000007 (ops 31-35)
I20260812 06:16:43.452630  7446 log.cc:1079] T eb52a41a60b044c99169cb1e7c23222d P 7477e4b95a4b40798320ef6f1e760237: Deleting log segment in path: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515401677830-7331-0/minicluster-data/ts-0-root/wals/eb52a41a60b044c99169cb1e7c23222d/wal-000000008 (ops 36-40)
I20260812 06:16:43.452662  7446 log.cc:1079] T eb52a41a60b044c99169cb1e7c23222d P 7477e4b95a4b40798320ef6f1e760237: Deleting log segment in path: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515401677830-7331-0/minicluster-data/ts-0-root/wals/eb52a41a60b044c99169cb1e7c23222d/wal-000000009 (ops 41-45)
I20260812 06:16:43.452692  7446 log.cc:1079] T eb52a41a60b044c99169cb1e7c23222d P 7477e4b95a4b40798320ef6f1e760237: Deleting log segment in path: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515401677830-7331-0/minicluster-data/ts-0-root/wals/eb52a41a60b044c99169cb1e7c23222d/wal-000000010 (ops 46-50)
I20260812 06:16:43.452721  7446 log.cc:1079] T eb52a41a60b044c99169cb1e7c23222d P 7477e4b95a4b40798320ef6f1e760237: Deleting log segment in path: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515401677830-7331-0/minicluster-data/ts-0-root/wals/eb52a41a60b044c99169cb1e7c23222d/wal-000000011 (ops 51-55)
I20260812 06:16:43.452750  7446 log.cc:1079] T eb52a41a60b044c99169cb1e7c23222d P 7477e4b95a4b40798320ef6f1e760237: Deleting log segment in path: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515401677830-7331-0/minicluster-data/ts-0-root/wals/eb52a41a60b044c99169cb1e7c23222d/wal-000000012 (ops 56-60)
I20260812 06:16:43.452785  7446 log.cc:1079] T eb52a41a60b044c99169cb1e7c23222d P 7477e4b95a4b40798320ef6f1e760237: Deleting log segment in path: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515401677830-7331-0/minicluster-data/ts-0-root/wals/eb52a41a60b044c99169cb1e7c23222d/wal-000000013 (ops 61-65)
I20260812 06:16:43.481400  7446 maintenance_manager.cc:643] P 7477e4b95a4b40798320ef6f1e760237: LogGCOp(eb52a41a60b044c99169cb1e7c23222d) complete. Timing: real 0.029s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:16:43.481863  7519 maintenance_manager.cc:419] P 7477e4b95a4b40798320ef6f1e760237: Scheduling UndoDeltaBlockGCOp(eb52a41a60b044c99169cb1e7c23222d): 463 bytes on disk
I20260812 06:16:43.482348  7446 maintenance_manager.cc:643] P 7477e4b95a4b40798320ef6f1e760237: UndoDeltaBlockGCOp(eb52a41a60b044c99169cb1e7c23222d) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":51,"lbm_reads_lt_1ms":4}
I20260812 06:16:43.482887  7519 maintenance_manager.cc:419] P 7477e4b95a4b40798320ef6f1e760237: Scheduling FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d): perf score=2.188937
I20260812 06:16:43.497063  7446 maintenance_manager.cc:643] P 7477e4b95a4b40798320ef6f1e760237: FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d) complete. Timing: real 0.014s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4015,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:43.497498  7519 maintenance_manager.cc:419] P 7477e4b95a4b40798320ef6f1e760237: Scheduling FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d): perf score=2.188937
I20260812 06:16:43.507943  7446 maintenance_manager.cc:643] P 7477e4b95a4b40798320ef6f1e760237: FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3859,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:43.508435  7519 maintenance_manager.cc:419] P 7477e4b95a4b40798320ef6f1e760237: Scheduling MajorDeltaCompactionOp(eb52a41a60b044c99169cb1e7c23222d): perf score=1.000000
I20260812 06:16:43.688323  7446 maintenance_manager.cc:643] P 7477e4b95a4b40798320ef6f1e760237: MajorDeltaCompactionOp(eb52a41a60b044c99169cb1e7c23222d) complete. Timing: real 0.180s	user 0.143s	sys 0.031s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836376,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":374,"lbm_read_time_us":10626,"lbm_reads_lt_1ms":674,"lbm_write_time_us":38142,"lbm_writes_lt_1ms":643,"mutex_wait_us":71,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":10240,"thread_start_us":101,"threads_started":1,"update_count":3000}
I20260812 06:16:43.688827  7519 maintenance_manager.cc:419] P 7477e4b95a4b40798320ef6f1e760237: Scheduling FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d): perf score=14.095187
I20260812 06:16:43.740237  7446 maintenance_manager.cc:643] P 7477e4b95a4b40798320ef6f1e760237: FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d) complete. Timing: real 0.050s	user 0.033s	sys 0.009s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19360,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:16:43.740723  7519 maintenance_manager.cc:419] P 7477e4b95a4b40798320ef6f1e760237: Scheduling FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d): perf score=2.188937
I20260812 06:16:43.752548  7446 maintenance_manager.cc:643] P 7477e4b95a4b40798320ef6f1e760237: FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d) complete. Timing: real 0.012s	user 0.008s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4050,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:43.753193  7519 maintenance_manager.cc:419] P 7477e4b95a4b40798320ef6f1e760237: Scheduling MajorDeltaCompactionOp(eb52a41a60b044c99169cb1e7c23222d): perf score=1.000000
I20260812 06:16:43.909597  7446 maintenance_manager.cc:643] P 7477e4b95a4b40798320ef6f1e760237: MajorDeltaCompactionOp(eb52a41a60b044c99169cb1e7c23222d) complete. Timing: real 0.156s	user 0.105s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":3626,"lbm_read_time_us":9733,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28417,"lbm_writes_lt_1ms":543,"mutex_wait_us":3298,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9856,"update_count":2500}
I20260812 06:16:43.910391  7519 maintenance_manager.cc:419] P 7477e4b95a4b40798320ef6f1e760237: Scheduling FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d): perf score=13.103000
I20260812 06:16:43.955097  7446 maintenance_manager.cc:643] P 7477e4b95a4b40798320ef6f1e760237: FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d) complete. Timing: real 0.044s	user 0.024s	sys 0.019s Metrics: {"bytes_written":14850989,"delete_count":0,"lbm_write_time_us":19806,"lbm_writes_lt_1ms":365,"reinsert_count":0,"update_count":1810}
I20260812 06:16:43.955569  7519 maintenance_manager.cc:419] P 7477e4b95a4b40798320ef6f1e760237: Scheduling FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d): perf score=1.000000
I20260812 06:16:43.964776  7446 maintenance_manager.cc:643] P 7477e4b95a4b40798320ef6f1e760237: FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d) complete. Timing: real 0.009s	user 0.001s	sys 0.005s Metrics: {"bytes_written":1969356,"delete_count":0,"lbm_write_time_us":2594,"lbm_writes_lt_1ms":51,"reinsert_count":0,"update_count":240}
I20260812 06:16:43.965219  7519 maintenance_manager.cc:419] P 7477e4b95a4b40798320ef6f1e760237: Scheduling MajorDeltaCompactionOp(eb52a41a60b044c99169cb1e7c23222d): perf score=1.000000
I20260812 06:16:44.121737  7446 maintenance_manager.cc:643] P 7477e4b95a4b40798320ef6f1e760237: MajorDeltaCompactionOp(eb52a41a60b044c99169cb1e7c23222d) complete. Timing: real 0.156s	user 0.094s	sys 0.053s Metrics: {"cfile_cache_miss":442,"cfile_cache_miss_bytes":21041509,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":265,"lbm_read_time_us":9187,"lbm_reads_lt_1ms":474,"lbm_write_time_us":25227,"lbm_writes_lt_1ms":453,"mutex_wait_us":31,"peak_mem_usage":51099678,"reinsert_count":0,"spinlock_wait_cycles":9984,"update_count":2050}
I20260812 06:16:44.122411  7519 maintenance_manager.cc:419] P 7477e4b95a4b40798320ef6f1e760237: Scheduling FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d): perf score=14.095187
I20260812 06:16:44.173664  7446 maintenance_manager.cc:643] P 7477e4b95a4b40798320ef6f1e760237: FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d) complete. Timing: real 0.051s	user 0.038s	sys 0.007s Metrics: {"bytes_written":15999660,"delete_count":0,"lbm_write_time_us":21460,"lbm_writes_lt_1ms":393,"reinsert_count":0,"update_count":1950}
I20260812 06:16:44.174202  7519 maintenance_manager.cc:419] P 7477e4b95a4b40798320ef6f1e760237: Scheduling FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d): perf score=2.188937
I20260812 06:16:44.192129  7446 maintenance_manager.cc:643] P 7477e4b95a4b40798320ef6f1e760237: FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d) complete. Timing: real 0.018s	user 0.004s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4135,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:44.192757  7519 maintenance_manager.cc:419] P 7477e4b95a4b40798320ef6f1e760237: Scheduling MajorDeltaCompactionOp(eb52a41a60b044c99169cb1e7c23222d): perf score=1.000000
I20260812 06:16:44.384654  7446 maintenance_manager.cc:643] P 7477e4b95a4b40798320ef6f1e760237: MajorDeltaCompactionOp(eb52a41a60b044c99169cb1e7c23222d) complete. Timing: real 0.192s	user 0.116s	sys 0.064s Metrics: {"cfile_cache_miss":522,"cfile_cache_miss_bytes":24323482,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":232,"lbm_read_time_us":14687,"lbm_reads_lt_1ms":562,"lbm_write_time_us":31083,"lbm_writes_lt_1ms":533,"mutex_wait_us":24,"peak_mem_usage":61665166,"reinsert_count":0,"spinlock_wait_cycles":15488,"update_count":2450}
I20260812 06:16:44.385264  7519 maintenance_manager.cc:419] P 7477e4b95a4b40798320ef6f1e760237: Scheduling FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d): perf score=14.095187
I20260812 06:16:44.435451  7446 maintenance_manager.cc:643] P 7477e4b95a4b40798320ef6f1e760237: FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d) complete. Timing: real 0.050s	user 0.022s	sys 0.020s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":18993,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:44.435962  7519 maintenance_manager.cc:419] P 7477e4b95a4b40798320ef6f1e760237: Scheduling FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d): perf score=2.188937
I20260812 06:16:44.448632  7446 maintenance_manager.cc:643] P 7477e4b95a4b40798320ef6f1e760237: FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4350,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:44.449442  7519 maintenance_manager.cc:419] P 7477e4b95a4b40798320ef6f1e760237: Scheduling MajorDeltaCompactionOp(eb52a41a60b044c99169cb1e7c23222d): perf score=1.000000
I20260812 06:16:44.648870  7446 maintenance_manager.cc:643] P 7477e4b95a4b40798320ef6f1e760237: MajorDeltaCompactionOp(eb52a41a60b044c99169cb1e7c23222d) complete. Timing: real 0.199s	user 0.129s	sys 0.055s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733726,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":645,"lbm_read_time_us":10674,"lbm_reads_lt_1ms":572,"lbm_write_time_us":35009,"lbm_writes_lt_1ms":543,"mutex_wait_us":68,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4608,"update_count":2500}
I20260812 06:16:44.649703  7519 maintenance_manager.cc:419] P 7477e4b95a4b40798320ef6f1e760237: Scheduling FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d): perf score=14.095187
I20260812 06:16:44.704533  7446 maintenance_manager.cc:643] P 7477e4b95a4b40798320ef6f1e760237: FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d) complete. Timing: real 0.055s	user 0.029s	sys 0.021s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23650,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2000}
I20260812 06:16:44.705008  7519 maintenance_manager.cc:419] P 7477e4b95a4b40798320ef6f1e760237: Scheduling FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d): perf score=2.188937
I20260812 06:16:44.717065  7446 maintenance_manager.cc:643] P 7477e4b95a4b40798320ef6f1e760237: FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d) complete. Timing: real 0.012s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4215,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:44.717577  7519 maintenance_manager.cc:419] P 7477e4b95a4b40798320ef6f1e760237: Scheduling MajorDeltaCompactionOp(eb52a41a60b044c99169cb1e7c23222d): perf score=1.000000
I20260812 06:16:44.889835  7446 maintenance_manager.cc:643] P 7477e4b95a4b40798320ef6f1e760237: MajorDeltaCompactionOp(eb52a41a60b044c99169cb1e7c23222d) complete. Timing: real 0.172s	user 0.116s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733724,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":168,"lbm_read_time_us":11544,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33333,"lbm_writes_lt_1ms":543,"mutex_wait_us":71,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9856,"update_count":2500}
I20260812 06:16:44.890612  7519 maintenance_manager.cc:419] P 7477e4b95a4b40798320ef6f1e760237: Scheduling FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d): perf score=14.095187
I20260812 06:16:44.940492  7446 maintenance_manager.cc:643] P 7477e4b95a4b40798320ef6f1e760237: FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d) complete. Timing: real 0.050s	user 0.035s	sys 0.008s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20074,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:44.941017  7519 maintenance_manager.cc:419] P 7477e4b95a4b40798320ef6f1e760237: Scheduling FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d): perf score=2.188937
I20260812 06:16:44.952273  7446 maintenance_manager.cc:643] P 7477e4b95a4b40798320ef6f1e760237: FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4233,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:44.952914  7519 maintenance_manager.cc:419] P 7477e4b95a4b40798320ef6f1e760237: Scheduling FlushMRSOp(eb52a41a60b044c99169cb1e7c23222d): perf score=1.000000
I20260812 06:16:44.984194  7446 maintenance_manager.cc:643] P 7477e4b95a4b40798320ef6f1e760237: FlushMRSOp(eb52a41a60b044c99169cb1e7c23222d) complete. Timing: real 0.031s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":70,"dirs.run_cpu_time_us":270,"dirs.run_wall_time_us":1634,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1556,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:16:44.984928  7519 maintenance_manager.cc:419] P 7477e4b95a4b40798320ef6f1e760237: Scheduling LogGCOp(eb52a41a60b044c99169cb1e7c23222d): free 128867403 bytes of WAL
I20260812 06:16:44.985172  7446 log_reader.cc:385] T eb52a41a60b044c99169cb1e7c23222d: removed 13 log segments from log reader
I20260812 06:16:44.985219  7446 log.cc:1079] T eb52a41a60b044c99169cb1e7c23222d P 7477e4b95a4b40798320ef6f1e760237: Deleting log segment in path: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515401677830-7331-0/minicluster-data/ts-0-root/wals/eb52a41a60b044c99169cb1e7c23222d/wal-000000014 (ops 66-70)
I20260812 06:16:44.985247  7446 log.cc:1079] T eb52a41a60b044c99169cb1e7c23222d P 7477e4b95a4b40798320ef6f1e760237: Deleting log segment in path: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515401677830-7331-0/minicluster-data/ts-0-root/wals/eb52a41a60b044c99169cb1e7c23222d/wal-000000015 (ops 71-75)
I20260812 06:16:44.985291  7446 log.cc:1079] T eb52a41a60b044c99169cb1e7c23222d P 7477e4b95a4b40798320ef6f1e760237: Deleting log segment in path: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515401677830-7331-0/minicluster-data/ts-0-root/wals/eb52a41a60b044c99169cb1e7c23222d/wal-000000016 (ops 76-80)
I20260812 06:16:44.985333  7446 log.cc:1079] T eb52a41a60b044c99169cb1e7c23222d P 7477e4b95a4b40798320ef6f1e760237: Deleting log segment in path: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515401677830-7331-0/minicluster-data/ts-0-root/wals/eb52a41a60b044c99169cb1e7c23222d/wal-000000017 (ops 81-85)
I20260812 06:16:44.985360  7446 log.cc:1079] T eb52a41a60b044c99169cb1e7c23222d P 7477e4b95a4b40798320ef6f1e760237: Deleting log segment in path: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515401677830-7331-0/minicluster-data/ts-0-root/wals/eb52a41a60b044c99169cb1e7c23222d/wal-000000018 (ops 86-90)
I20260812 06:16:44.985417  7446 log.cc:1079] T eb52a41a60b044c99169cb1e7c23222d P 7477e4b95a4b40798320ef6f1e760237: Deleting log segment in path: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515401677830-7331-0/minicluster-data/ts-0-root/wals/eb52a41a60b044c99169cb1e7c23222d/wal-000000019 (ops 91-94)
I20260812 06:16:44.985464  7446 log.cc:1079] T eb52a41a60b044c99169cb1e7c23222d P 7477e4b95a4b40798320ef6f1e760237: Deleting log segment in path: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515401677830-7331-0/minicluster-data/ts-0-root/wals/eb52a41a60b044c99169cb1e7c23222d/wal-000000020 (ops 95-99)
I20260812 06:16:44.985507  7446 log.cc:1079] T eb52a41a60b044c99169cb1e7c23222d P 7477e4b95a4b40798320ef6f1e760237: Deleting log segment in path: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515401677830-7331-0/minicluster-data/ts-0-root/wals/eb52a41a60b044c99169cb1e7c23222d/wal-000000021 (ops 100-104)
I20260812 06:16:44.985546  7446 log.cc:1079] T eb52a41a60b044c99169cb1e7c23222d P 7477e4b95a4b40798320ef6f1e760237: Deleting log segment in path: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515401677830-7331-0/minicluster-data/ts-0-root/wals/eb52a41a60b044c99169cb1e7c23222d/wal-000000022 (ops 105-108)
I20260812 06:16:44.985586  7446 log.cc:1079] T eb52a41a60b044c99169cb1e7c23222d P 7477e4b95a4b40798320ef6f1e760237: Deleting log segment in path: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515401677830-7331-0/minicluster-data/ts-0-root/wals/eb52a41a60b044c99169cb1e7c23222d/wal-000000023 (ops 109-113)
I20260812 06:16:44.985626  7446 log.cc:1079] T eb52a41a60b044c99169cb1e7c23222d P 7477e4b95a4b40798320ef6f1e760237: Deleting log segment in path: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515401677830-7331-0/minicluster-data/ts-0-root/wals/eb52a41a60b044c99169cb1e7c23222d/wal-000000024 (ops 114-118)
I20260812 06:16:44.985667  7446 log.cc:1079] T eb52a41a60b044c99169cb1e7c23222d P 7477e4b95a4b40798320ef6f1e760237: Deleting log segment in path: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515401677830-7331-0/minicluster-data/ts-0-root/wals/eb52a41a60b044c99169cb1e7c23222d/wal-000000025 (ops 119-122)
I20260812 06:16:44.985708  7446 log.cc:1079] T eb52a41a60b044c99169cb1e7c23222d P 7477e4b95a4b40798320ef6f1e760237: Deleting log segment in path: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515401677830-7331-0/minicluster-data/ts-0-root/wals/eb52a41a60b044c99169cb1e7c23222d/wal-000000026 (ops 123-127)
I20260812 06:16:45.015280  7446 maintenance_manager.cc:643] P 7477e4b95a4b40798320ef6f1e760237: LogGCOp(eb52a41a60b044c99169cb1e7c23222d) complete. Timing: real 0.030s	user 0.002s	sys 0.027s Metrics: {}
I20260812 06:16:45.015774  7519 maintenance_manager.cc:419] P 7477e4b95a4b40798320ef6f1e760237: Scheduling FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d): perf score=3.181125
I20260812 06:16:45.033787  7446 maintenance_manager.cc:643] P 7477e4b95a4b40798320ef6f1e760237: FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d) complete. Timing: real 0.018s	user 0.008s	sys 0.008s Metrics: {"bytes_written":4512902,"delete_count":0,"lbm_write_time_us":7207,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:16:45.034322  7519 maintenance_manager.cc:419] P 7477e4b95a4b40798320ef6f1e760237: Scheduling UndoDeltaBlockGCOp(eb52a41a60b044c99169cb1e7c23222d): 482 bytes on disk
I20260812 06:16:45.034739  7446 maintenance_manager.cc:643] P 7477e4b95a4b40798320ef6f1e760237: UndoDeltaBlockGCOp(eb52a41a60b044c99169cb1e7c23222d) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4}
I20260812 06:16:45.035247  7519 maintenance_manager.cc:419] P 7477e4b95a4b40798320ef6f1e760237: Scheduling FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d): perf score=2.188937
I20260812 06:16:45.055406  7446 maintenance_manager.cc:643] P 7477e4b95a4b40798320ef6f1e760237: FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d) complete. Timing: real 0.020s	user 0.007s	sys 0.011s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4097,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:45.055970  7519 maintenance_manager.cc:419] P 7477e4b95a4b40798320ef6f1e760237: Scheduling MajorDeltaCompactionOp(eb52a41a60b044c99169cb1e7c23222d): perf score=1.000000
I20260812 06:16:45.295099  7446 maintenance_manager.cc:643] P 7477e4b95a4b40798320ef6f1e760237: MajorDeltaCompactionOp(eb52a41a60b044c99169cb1e7c23222d) complete. Timing: real 0.239s	user 0.158s	sys 0.076s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32938773,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":796,"lbm_read_time_us":18395,"lbm_reads_lt_1ms":774,"lbm_write_time_us":38171,"lbm_writes_lt_1ms":743,"mutex_wait_us":357,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":1664,"thread_start_us":79,"threads_started":1,"update_count":3500}
I20260812 06:16:45.296321  7519 maintenance_manager.cc:419] P 7477e4b95a4b40798320ef6f1e760237: Scheduling FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d): perf score=15.087375
I20260812 06:16:45.358117  7446 maintenance_manager.cc:643] P 7477e4b95a4b40798320ef6f1e760237: FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d) complete. Timing: real 0.062s	user 0.026s	sys 0.035s Metrics: {"bytes_written":16820143,"delete_count":0,"lbm_write_time_us":23116,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:16:45.358626  7519 maintenance_manager.cc:419] P 7477e4b95a4b40798320ef6f1e760237: Scheduling FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d): perf score=2.188937
I20260812 06:16:45.372377  7446 maintenance_manager.cc:643] P 7477e4b95a4b40798320ef6f1e760237: FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d) complete. Timing: real 0.014s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4322,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:45.372829  7519 maintenance_manager.cc:419] P 7477e4b95a4b40798320ef6f1e760237: Scheduling FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d): perf score=2.188937
I20260812 06:16:45.383268  7446 maintenance_manager.cc:643] P 7477e4b95a4b40798320ef6f1e760237: FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4128,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:45.383682  7519 maintenance_manager.cc:419] P 7477e4b95a4b40798320ef6f1e760237: Scheduling MajorDeltaCompactionOp(eb52a41a60b044c99169cb1e7c23222d): perf score=1.000000
I20260812 06:16:45.586773  7446 maintenance_manager.cc:643] P 7477e4b95a4b40798320ef6f1e760237: MajorDeltaCompactionOp(eb52a41a60b044c99169cb1e7c23222d) complete. Timing: real 0.203s	user 0.113s	sys 0.089s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28836242,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1294,"lbm_read_time_us":15092,"lbm_reads_lt_1ms":673,"lbm_write_time_us":33319,"lbm_writes_lt_1ms":643,"mutex_wait_us":330,"peak_mem_usage":75542472,"reinsert_count":0,"update_count":3000}
I20260812 06:16:45.587587  7519 maintenance_manager.cc:419] P 7477e4b95a4b40798320ef6f1e760237: Scheduling FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d): perf score=14.095187
I20260812 06:16:45.641433  7446 maintenance_manager.cc:643] P 7477e4b95a4b40798320ef6f1e760237: FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d) complete. Timing: real 0.054s	user 0.033s	sys 0.017s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":23117,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:45.642117  7519 maintenance_manager.cc:419] P 7477e4b95a4b40798320ef6f1e760237: Scheduling FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d): perf score=2.188937
I20260812 06:16:45.659487  7446 maintenance_manager.cc:643] P 7477e4b95a4b40798320ef6f1e760237: FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d) complete. Timing: real 0.017s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6454,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:45.660092  7519 maintenance_manager.cc:419] P 7477e4b95a4b40798320ef6f1e760237: Scheduling MajorDeltaCompactionOp(eb52a41a60b044c99169cb1e7c23222d): perf score=1.000000
I20260812 06:16:45.838063  7446 maintenance_manager.cc:643] P 7477e4b95a4b40798320ef6f1e760237: MajorDeltaCompactionOp(eb52a41a60b044c99169cb1e7c23222d) complete. Timing: real 0.178s	user 0.095s	sys 0.081s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733725,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":934,"lbm_read_time_us":11483,"lbm_reads_lt_1ms":564,"lbm_write_time_us":32123,"lbm_writes_lt_1ms":543,"mutex_wait_us":60,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:16:45.838882  7519 maintenance_manager.cc:419] P 7477e4b95a4b40798320ef6f1e760237: Scheduling FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d): perf score=15.087375
I20260812 06:16:45.892788  7446 maintenance_manager.cc:643] P 7477e4b95a4b40798320ef6f1e760237: FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d) complete. Timing: real 0.054s	user 0.019s	sys 0.033s Metrics: {"bytes_written":16820143,"delete_count":0,"lbm_write_time_us":22584,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:16:45.893293  7519 maintenance_manager.cc:419] P 7477e4b95a4b40798320ef6f1e760237: Scheduling FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d): perf score=2.188937
I20260812 06:16:45.914467  7446 maintenance_manager.cc:643] P 7477e4b95a4b40798320ef6f1e760237: FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d) complete. Timing: real 0.021s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4524,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:45.914950  7519 maintenance_manager.cc:419] P 7477e4b95a4b40798320ef6f1e760237: Scheduling FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d): perf score=2.188937
I20260812 06:16:45.928165  7446 maintenance_manager.cc:643] P 7477e4b95a4b40798320ef6f1e760237: FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d) complete. Timing: real 0.013s	user 0.004s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5055,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:45.928682  7519 maintenance_manager.cc:419] P 7477e4b95a4b40798320ef6f1e760237: Scheduling MajorDeltaCompactionOp(eb52a41a60b044c99169cb1e7c23222d): perf score=1.000000
I20260812 06:16:46.125584  7446 maintenance_manager.cc:643] P 7477e4b95a4b40798320ef6f1e760237: MajorDeltaCompactionOp(eb52a41a60b044c99169cb1e7c23222d) complete. Timing: real 0.197s	user 0.132s	sys 0.064s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28836242,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":349,"lbm_read_time_us":13807,"lbm_reads_lt_1ms":673,"lbm_write_time_us":35300,"lbm_writes_lt_1ms":643,"mutex_wait_us":25,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":17152,"update_count":3000}
I20260812 06:16:46.126411  7519 maintenance_manager.cc:419] P 7477e4b95a4b40798320ef6f1e760237: Scheduling FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d): perf score=14.095187
I20260812 06:16:46.187093  7446 maintenance_manager.cc:643] P 7477e4b95a4b40798320ef6f1e760237: FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d) complete. Timing: real 0.060s	user 0.043s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":25555,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:46.187894  7519 maintenance_manager.cc:419] P 7477e4b95a4b40798320ef6f1e760237: Scheduling FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d): perf score=2.188937
I20260812 06:16:46.203609  7446 maintenance_manager.cc:643] P 7477e4b95a4b40798320ef6f1e760237: FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5707,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:46.204161  7519 maintenance_manager.cc:419] P 7477e4b95a4b40798320ef6f1e760237: Scheduling MajorDeltaCompactionOp(eb52a41a60b044c99169cb1e7c23222d): perf score=1.000000
I20260812 06:16:46.376750  7446 maintenance_manager.cc:643] P 7477e4b95a4b40798320ef6f1e760237: MajorDeltaCompactionOp(eb52a41a60b044c99169cb1e7c23222d) complete. Timing: real 0.172s	user 0.110s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733724,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1370,"lbm_read_time_us":10960,"lbm_reads_lt_1ms":564,"lbm_write_time_us":28203,"lbm_writes_lt_1ms":543,"mutex_wait_us":480,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:16:46.377337  7519 maintenance_manager.cc:419] P 7477e4b95a4b40798320ef6f1e760237: Scheduling FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d): perf score=15.087375
I20260812 06:16:46.431074  7446 maintenance_manager.cc:643] P 7477e4b95a4b40798320ef6f1e760237: FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d) complete. Timing: real 0.054s	user 0.037s	sys 0.015s Metrics: {"bytes_written":16820142,"delete_count":0,"lbm_write_time_us":23926,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:16:46.431548  7519 maintenance_manager.cc:419] P 7477e4b95a4b40798320ef6f1e760237: Scheduling FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d): perf score=2.188937
I20260812 06:16:46.450708  7446 maintenance_manager.cc:643] P 7477e4b95a4b40798320ef6f1e760237: FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d) complete. Timing: real 0.019s	user 0.004s	sys 0.009s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5380,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:46.451443  7519 maintenance_manager.cc:419] P 7477e4b95a4b40798320ef6f1e760237: Scheduling FlushMRSOp(eb52a41a60b044c99169cb1e7c23222d): perf score=1.000000
I20260812 06:16:46.493085  7446 maintenance_manager.cc:643] P 7477e4b95a4b40798320ef6f1e760237: FlushMRSOp(eb52a41a60b044c99169cb1e7c23222d) complete. Timing: real 0.041s	user 0.027s	sys 0.002s Metrics: {"bytes_written":1234477,"cfile_init":1,"dirs.queue_time_us":78,"dirs.run_cpu_time_us":205,"dirs.run_wall_time_us":1111,"drs_written":1,"lbm_read_time_us":109,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2742,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":38,"peak_mem_usage":0,"rows_written":30}
I20260812 06:16:46.494199  7519 maintenance_manager.cc:419] P 7477e4b95a4b40798320ef6f1e760237: Scheduling FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d): perf score=3.181125
I20260812 06:16:46.508955  7446 maintenance_manager.cc:643] P 7477e4b95a4b40798320ef6f1e760237: FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d) complete. Timing: real 0.015s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4389832,"delete_count":0,"lbm_write_time_us":4265,"lbm_writes_lt_1ms":110,"reinsert_count":0,"update_count":535}
I20260812 06:16:46.509428  7519 maintenance_manager.cc:419] P 7477e4b95a4b40798320ef6f1e760237: Scheduling LogGCOp(eb52a41a60b044c99169cb1e7c23222d): free 124257554 bytes of WAL
I20260812 06:16:46.509644  7446 log_reader.cc:385] T eb52a41a60b044c99169cb1e7c23222d: removed 12 log segments from log reader
I20260812 06:16:46.509687  7446 log.cc:1079] T eb52a41a60b044c99169cb1e7c23222d P 7477e4b95a4b40798320ef6f1e760237: Deleting log segment in path: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515401677830-7331-0/minicluster-data/ts-0-root/wals/eb52a41a60b044c99169cb1e7c23222d/wal-000000027 (ops 128-132)
I20260812 06:16:46.509716  7446 log.cc:1079] T eb52a41a60b044c99169cb1e7c23222d P 7477e4b95a4b40798320ef6f1e760237: Deleting log segment in path: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515401677830-7331-0/minicluster-data/ts-0-root/wals/eb52a41a60b044c99169cb1e7c23222d/wal-000000028 (ops 133-137)
I20260812 06:16:46.509733  7446 log.cc:1079] T eb52a41a60b044c99169cb1e7c23222d P 7477e4b95a4b40798320ef6f1e760237: Deleting log segment in path: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515401677830-7331-0/minicluster-data/ts-0-root/wals/eb52a41a60b044c99169cb1e7c23222d/wal-000000029 (ops 138-142)
I20260812 06:16:46.509804  7446 log.cc:1079] T eb52a41a60b044c99169cb1e7c23222d P 7477e4b95a4b40798320ef6f1e760237: Deleting log segment in path: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515401677830-7331-0/minicluster-data/ts-0-root/wals/eb52a41a60b044c99169cb1e7c23222d/wal-000000030 (ops 143-147)
I20260812 06:16:46.509863  7446 log.cc:1079] T eb52a41a60b044c99169cb1e7c23222d P 7477e4b95a4b40798320ef6f1e760237: Deleting log segment in path: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515401677830-7331-0/minicluster-data/ts-0-root/wals/eb52a41a60b044c99169cb1e7c23222d/wal-000000031 (ops 148-152)
I20260812 06:16:46.509902  7446 log.cc:1079] T eb52a41a60b044c99169cb1e7c23222d P 7477e4b95a4b40798320ef6f1e760237: Deleting log segment in path: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515401677830-7331-0/minicluster-data/ts-0-root/wals/eb52a41a60b044c99169cb1e7c23222d/wal-000000032 (ops 153-156)
I20260812 06:16:46.509931  7446 log.cc:1079] T eb52a41a60b044c99169cb1e7c23222d P 7477e4b95a4b40798320ef6f1e760237: Deleting log segment in path: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515401677830-7331-0/minicluster-data/ts-0-root/wals/eb52a41a60b044c99169cb1e7c23222d/wal-000000033 (ops 157-161)
I20260812 06:16:46.509972  7446 log.cc:1079] T eb52a41a60b044c99169cb1e7c23222d P 7477e4b95a4b40798320ef6f1e760237: Deleting log segment in path: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515401677830-7331-0/minicluster-data/ts-0-root/wals/eb52a41a60b044c99169cb1e7c23222d/wal-000000034 (ops 162-166)
I20260812 06:16:46.510008  7446 log.cc:1079] T eb52a41a60b044c99169cb1e7c23222d P 7477e4b95a4b40798320ef6f1e760237: Deleting log segment in path: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515401677830-7331-0/minicluster-data/ts-0-root/wals/eb52a41a60b044c99169cb1e7c23222d/wal-000000035 (ops 167-171)
I20260812 06:16:46.510046  7446 log.cc:1079] T eb52a41a60b044c99169cb1e7c23222d P 7477e4b95a4b40798320ef6f1e760237: Deleting log segment in path: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515401677830-7331-0/minicluster-data/ts-0-root/wals/eb52a41a60b044c99169cb1e7c23222d/wal-000000036 (ops 172-176)
I20260812 06:16:46.510082  7446 log.cc:1079] T eb52a41a60b044c99169cb1e7c23222d P 7477e4b95a4b40798320ef6f1e760237: Deleting log segment in path: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515401677830-7331-0/minicluster-data/ts-0-root/wals/eb52a41a60b044c99169cb1e7c23222d/wal-000000037 (ops 177-181)
I20260812 06:16:46.510120  7446 log.cc:1079] T eb52a41a60b044c99169cb1e7c23222d P 7477e4b95a4b40798320ef6f1e760237: Deleting log segment in path: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515401677830-7331-0/minicluster-data/ts-0-root/wals/eb52a41a60b044c99169cb1e7c23222d/wal-000000038 (ops 182-186)
I20260812 06:16:46.537546  7446 maintenance_manager.cc:643] P 7477e4b95a4b40798320ef6f1e760237: LogGCOp(eb52a41a60b044c99169cb1e7c23222d) complete. Timing: real 0.028s	user 0.000s	sys 0.024s Metrics: {}
I20260812 06:16:46.538233  7519 maintenance_manager.cc:419] P 7477e4b95a4b40798320ef6f1e760237: Scheduling FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d): perf score=3.181125
I20260812 06:16:46.549459  7446 maintenance_manager.cc:643] P 7477e4b95a4b40798320ef6f1e760237: FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4225735,"delete_count":0,"lbm_write_time_us":4166,"lbm_writes_lt_1ms":106,"reinsert_count":0,"update_count":515}
I20260812 06:16:46.550071  7519 maintenance_manager.cc:419] P 7477e4b95a4b40798320ef6f1e760237: Scheduling FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d): perf score=2.188937
I20260812 06:16:46.559636  7446 maintenance_manager.cc:643] P 7477e4b95a4b40798320ef6f1e760237: FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3741,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:46.560088  7519 maintenance_manager.cc:419] P 7477e4b95a4b40798320ef6f1e760237: Scheduling MajorDeltaCompactionOp(eb52a41a60b044c99169cb1e7c23222d): perf score=1.000000
I20260812 06:16:46.776113  7331 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.841s	user 1.768s	sys 0.141s
I20260812 06:16:46.784587  7446 maintenance_manager.cc:643] P 7477e4b95a4b40798320ef6f1e760237: MajorDeltaCompactionOp(eb52a41a60b044c99169cb1e7c23222d) complete. Timing: real 0.224s	user 0.139s	sys 0.084s Metrics: {"cfile_cache_miss":835,"cfile_cache_miss_bytes":37041298,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"lbm_read_time_us":17196,"lbm_reads_lt_1ms":871,"lbm_write_time_us":41876,"lbm_writes_lt_1ms":843,"peak_mem_usage":100395616,"reinsert_count":0,"update_count":4000}
I20260812 06:16:46.785089  7519 maintenance_manager.cc:419] P 7477e4b95a4b40798320ef6f1e760237: Scheduling UndoDeltaBlockGCOp(eb52a41a60b044c99169cb1e7c23222d): 472 bytes on disk
I20260812 06:16:46.785480  7446 maintenance_manager.cc:643] P 7477e4b95a4b40798320ef6f1e760237: UndoDeltaBlockGCOp(eb52a41a60b044c99169cb1e7c23222d) 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:16:46.786095  7519 maintenance_manager.cc:419] P 7477e4b95a4b40798320ef6f1e760237: Scheduling FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d): perf score=18.063937
I20260812 06:16:46.826795  7446 maintenance_manager.cc:643] P 7477e4b95a4b40798320ef6f1e760237: FlushDeltaMemStoresOp(eb52a41a60b044c99169cb1e7c23222d) complete. Timing: real 0.041s	user 0.018s	sys 0.021s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":19767,"lbm_writes_lt_1ms":503,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":2500}
I20260812 06:16:46.827315  7519 maintenance_manager.cc:419] P 7477e4b95a4b40798320ef6f1e760237: Scheduling MajorDeltaCompactionOp(eb52a41a60b044c99169cb1e7c23222d): perf score=1.000000
I20260812 06:16:46.856738  7331 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.080s	user 0.002s	sys 0.000s
I20260812 06:16:46.857682  7331 tablet_server.cc:179] TabletServer@127.7.40.193:0 shutting down...
I20260812 06:16:46.966508  7446 maintenance_manager.cc:643] P 7477e4b95a4b40798320ef6f1e760237: MajorDeltaCompactionOp(eb52a41a60b044c99169cb1e7c23222d) complete. Timing: real 0.139s	user 0.099s	sys 0.037s Metrics: {"cfile_cache_miss":531,"cfile_cache_miss_bytes":24733607,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":989,"lbm_read_time_us":9750,"lbm_reads_lt_1ms":567,"lbm_write_time_us":31487,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":542,"mutex_wait_us":121,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11136,"update_count":2500}
I20260812 06:16:46.967185  7331 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:16:46.967643  7331 tablet_replica.cc:333] T eb52a41a60b044c99169cb1e7c23222d P 7477e4b95a4b40798320ef6f1e760237: stopping tablet replica
I20260812 06:16:46.967903  7331 raft_consensus.cc:2243] T eb52a41a60b044c99169cb1e7c23222d P 7477e4b95a4b40798320ef6f1e760237 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:46.968171  7331 raft_consensus.cc:2272] T eb52a41a60b044c99169cb1e7c23222d P 7477e4b95a4b40798320ef6f1e760237 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:46.984331  7331 tablet_server.cc:196] TabletServer@127.7.40.193:0 shutdown complete.
I20260812 06:16:47.014398  7331 master.cc:562] Master@127.7.40.254:45451 shutting down...
I20260812 06:16:47.018407  7331 raft_consensus.cc:2243] T 00000000000000000000000000000000 P faf5aa209b034b51896eb96012733019 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:47.018592  7331 raft_consensus.cc:2272] T 00000000000000000000000000000000 P faf5aa209b034b51896eb96012733019 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:47.018651  7331 tablet_replica.cc:333] T 00000000000000000000000000000000 P faf5aa209b034b51896eb96012733019: stopping tablet replica
I20260812 06:16:47.031096  7331 master.cc:584] Master@127.7.40.254:45451 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5434 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:16:47.133805  7331 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.7.40.254:37041
I20260812 06:16:47.134298  7331 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:47.136384  7558 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:16:47.136408  7555 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:16:47.136466  7556 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:16:47.136504  7331 server_base.cc:1061] running on GCE node
I20260812 06:16:47.136811  7331 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:47.136858  7331 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:16:47.136874  7331 hybrid_clock.cc:648] HybridClock initialized: now 1786515407136874 us; error 0 us; skew 500 ppm
I20260812 06:16:47.137755  7331 webserver.cc:533] Webserver started at http://127.7.40.254:38831/ using document root <none> and password file <none>
I20260812 06:16:47.137976  7331 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:47.138041  7331 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:47.138129  7331 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:47.138602  7331 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401677830-7331-0/minicluster-data/master-0-root/instance:
uuid: "06b2d476398f4859ac7e6859169ae0ed"
format_stamp: "Formatted at 2026-08-12 06:16:47 on dist-test-slave-69rg"
I20260812 06:16:47.140162  7331 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:16:47.141100  7563 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:16:47.141388  7331 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:16:47.141477  7331 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401677830-7331-0/minicluster-data/master-0-root
uuid: "06b2d476398f4859ac7e6859169ae0ed"
format_stamp: "Formatted at 2026-08-12 06:16:47 on dist-test-slave-69rg"
I20260812 06:16:47.141554  7331 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401677830-7331-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401677830-7331-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401677830-7331-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:16:47.152738  7331 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:47.153147  7331 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:47.157747  7331 rpc_server.cc:307] RPC server started. Bound to: 127.7.40.254:37041
I20260812 06:16:47.159308  7629 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.7.40.254:37041 every 8 connection(s)
I20260812 06:16:47.159746  7630 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:16:47.165347  7630 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 06b2d476398f4859ac7e6859169ae0ed: Bootstrap starting.
I20260812 06:16:47.166349  7630 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 06b2d476398f4859ac7e6859169ae0ed: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:47.167524  7630 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 06b2d476398f4859ac7e6859169ae0ed: No bootstrap required, opened a new log
I20260812 06:16:47.167950  7630 raft_consensus.cc:359] T 00000000000000000000000000000000 P 06b2d476398f4859ac7e6859169ae0ed [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "06b2d476398f4859ac7e6859169ae0ed" member_type: VOTER }
I20260812 06:16:47.168068  7630 raft_consensus.cc:385] T 00000000000000000000000000000000 P 06b2d476398f4859ac7e6859169ae0ed [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:47.168150  7630 raft_consensus.cc:740] T 00000000000000000000000000000000 P 06b2d476398f4859ac7e6859169ae0ed [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 06b2d476398f4859ac7e6859169ae0ed, State: Initialized, Role: FOLLOWER
I20260812 06:16:47.168339  7630 consensus_queue.cc:260] T 00000000000000000000000000000000 P 06b2d476398f4859ac7e6859169ae0ed [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: "06b2d476398f4859ac7e6859169ae0ed" member_type: VOTER }
I20260812 06:16:47.168443  7630 raft_consensus.cc:399] T 00000000000000000000000000000000 P 06b2d476398f4859ac7e6859169ae0ed [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:47.168491  7630 raft_consensus.cc:493] T 00000000000000000000000000000000 P 06b2d476398f4859ac7e6859169ae0ed [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:47.168552  7630 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 06b2d476398f4859ac7e6859169ae0ed [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:47.169364  7630 raft_consensus.cc:515] T 00000000000000000000000000000000 P 06b2d476398f4859ac7e6859169ae0ed [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "06b2d476398f4859ac7e6859169ae0ed" member_type: VOTER }
I20260812 06:16:47.169533  7630 leader_election.cc:304] T 00000000000000000000000000000000 P 06b2d476398f4859ac7e6859169ae0ed [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: 06b2d476398f4859ac7e6859169ae0ed; no voters: 
I20260812 06:16:47.169750  7630 leader_election.cc:290] T 00000000000000000000000000000000 P 06b2d476398f4859ac7e6859169ae0ed [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:47.169874  7636 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 06b2d476398f4859ac7e6859169ae0ed [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:47.170099  7636 raft_consensus.cc:697] T 00000000000000000000000000000000 P 06b2d476398f4859ac7e6859169ae0ed [term 1 LEADER]: Becoming Leader. State: Replica: 06b2d476398f4859ac7e6859169ae0ed, State: Running, Role: LEADER
I20260812 06:16:47.170233  7636 consensus_queue.cc:237] T 00000000000000000000000000000000 P 06b2d476398f4859ac7e6859169ae0ed [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: "06b2d476398f4859ac7e6859169ae0ed" member_type: VOTER }
I20260812 06:16:47.170347  7630 sys_catalog.cc:565] T 00000000000000000000000000000000 P 06b2d476398f4859ac7e6859169ae0ed [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:16:47.170697  7637 sys_catalog.cc:455] T 00000000000000000000000000000000 P 06b2d476398f4859ac7e6859169ae0ed [sys.catalog]: SysCatalogTable state changed. Reason: New leader 06b2d476398f4859ac7e6859169ae0ed. Latest consensus state: current_term: 1 leader_uuid: "06b2d476398f4859ac7e6859169ae0ed" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "06b2d476398f4859ac7e6859169ae0ed" member_type: VOTER } }
I20260812 06:16:47.170792  7637 sys_catalog.cc:458] T 00000000000000000000000000000000 P 06b2d476398f4859ac7e6859169ae0ed [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:47.170681  7638 sys_catalog.cc:455] T 00000000000000000000000000000000 P 06b2d476398f4859ac7e6859169ae0ed [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "06b2d476398f4859ac7e6859169ae0ed" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "06b2d476398f4859ac7e6859169ae0ed" member_type: VOTER } }
I20260812 06:16:47.170886  7638 sys_catalog.cc:458] T 00000000000000000000000000000000 P 06b2d476398f4859ac7e6859169ae0ed [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:47.171116  7641 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:16:47.171964  7641 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:16:47.172495  7331 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:16:47.173947  7641 catalog_manager.cc:1383] Generated new cluster ID: d989628700a94982bbd933ddd47fd7d6
I20260812 06:16:47.174005  7641 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:16:47.180209  7641 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:16:47.180795  7641 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:16:47.188987  7641 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 06b2d476398f4859ac7e6859169ae0ed: Generated new TSK 0
I20260812 06:16:47.189210  7641 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:16:47.205132  7331 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:47.207254  7656 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:16:47.207369  7331 server_base.cc:1061] running on GCE node
W20260812 06:16:47.207389  7657 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:16:47.207398  7659 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:16:47.207796  7331 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:47.207862  7331 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:16:47.207890  7331 hybrid_clock.cc:648] HybridClock initialized: now 1786515407207888 us; error 0 us; skew 500 ppm
I20260812 06:16:47.208801  7331 webserver.cc:533] Webserver started at http://127.7.40.193:45973/ using document root <none> and password file <none>
I20260812 06:16:47.208985  7331 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:47.209057  7331 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:47.209139  7331 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:47.209556  7331 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401677830-7331-0/minicluster-data/ts-0-root/instance:
uuid: "d2c801da70cd4a8088a0dbcd15c0e1fd"
format_stamp: "Formatted at 2026-08-12 06:16:47 on dist-test-slave-69rg"
I20260812 06:16:47.211148  7331 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:16:47.212061  7664 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:16:47.212314  7331 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:16:47.212406  7331 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401677830-7331-0/minicluster-data/ts-0-root
uuid: "d2c801da70cd4a8088a0dbcd15c0e1fd"
format_stamp: "Formatted at 2026-08-12 06:16:47 on dist-test-slave-69rg"
I20260812 06:16:47.212492  7331 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401677830-7331-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401677830-7331-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401677830-7331-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:16:47.226902  7331 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:47.227313  7331 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:47.227631  7331 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:16:47.228161  7331 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:16:47.228222  7331 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:47.228276  7331 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:16:47.228317  7331 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:47.233093  7331 rpc_server.cc:307] RPC server started. Bound to: 127.7.40.193:36235
I20260812 06:16:47.235132  7738 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.7.40.193:36235 every 8 connection(s)
I20260812 06:16:47.244231  7739 heartbeater.cc:344] Connected to a master server at 127.7.40.254:37041
I20260812 06:16:47.244377  7739 heartbeater.cc:461] Registering TS with master...
I20260812 06:16:47.244638  7739 heartbeater.cc:507] Master 127.7.40.254:37041 requested a full tablet report, sending...
I20260812 06:16:47.245352  7581 ts_manager.cc:194] Registered new tserver with Master: d2c801da70cd4a8088a0dbcd15c0e1fd (127.7.40.193:36235)
I20260812 06:16:47.245394  7331 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.011354825s
I20260812 06:16:47.246284  7581 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:51376
I20260812 06:16:47.252651  7581 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:51382:
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:16:47.261382  7696 tablet_service.cc:1511] Processing CreateTablet for tablet 7c84d5de902a42d0b36e1dc3e98098fb (DEFAULT_TABLE table=heavy-update-compaction-test [id=64b9394a5fcf436daaa510c92faa19cd]), partition=
I20260812 06:16:47.261693  7696 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 7c84d5de902a42d0b36e1dc3e98098fb. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:16:47.263998  7753 tablet_bootstrap.cc:492] T 7c84d5de902a42d0b36e1dc3e98098fb P d2c801da70cd4a8088a0dbcd15c0e1fd: Bootstrap starting.
I20260812 06:16:47.264876  7753 tablet_bootstrap.cc:654] T 7c84d5de902a42d0b36e1dc3e98098fb P d2c801da70cd4a8088a0dbcd15c0e1fd: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:47.265975  7753 tablet_bootstrap.cc:492] T 7c84d5de902a42d0b36e1dc3e98098fb P d2c801da70cd4a8088a0dbcd15c0e1fd: No bootstrap required, opened a new log
I20260812 06:16:47.266069  7753 ts_tablet_manager.cc:1403] T 7c84d5de902a42d0b36e1dc3e98098fb P d2c801da70cd4a8088a0dbcd15c0e1fd: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:16:47.266614  7753 raft_consensus.cc:359] T 7c84d5de902a42d0b36e1dc3e98098fb P d2c801da70cd4a8088a0dbcd15c0e1fd [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d2c801da70cd4a8088a0dbcd15c0e1fd" member_type: VOTER last_known_addr { host: "127.7.40.193" port: 36235 } }
I20260812 06:16:47.266772  7753 raft_consensus.cc:385] T 7c84d5de902a42d0b36e1dc3e98098fb P d2c801da70cd4a8088a0dbcd15c0e1fd [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:47.266822  7753 raft_consensus.cc:740] T 7c84d5de902a42d0b36e1dc3e98098fb P d2c801da70cd4a8088a0dbcd15c0e1fd [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: d2c801da70cd4a8088a0dbcd15c0e1fd, State: Initialized, Role: FOLLOWER
I20260812 06:16:47.266964  7753 consensus_queue.cc:260] T 7c84d5de902a42d0b36e1dc3e98098fb P d2c801da70cd4a8088a0dbcd15c0e1fd [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: "d2c801da70cd4a8088a0dbcd15c0e1fd" member_type: VOTER last_known_addr { host: "127.7.40.193" port: 36235 } }
I20260812 06:16:47.267062  7753 raft_consensus.cc:399] T 7c84d5de902a42d0b36e1dc3e98098fb P d2c801da70cd4a8088a0dbcd15c0e1fd [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:47.267093  7753 raft_consensus.cc:493] T 7c84d5de902a42d0b36e1dc3e98098fb P d2c801da70cd4a8088a0dbcd15c0e1fd [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:47.267129  7753 raft_consensus.cc:3060] T 7c84d5de902a42d0b36e1dc3e98098fb P d2c801da70cd4a8088a0dbcd15c0e1fd [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:47.267844  7753 raft_consensus.cc:515] T 7c84d5de902a42d0b36e1dc3e98098fb P d2c801da70cd4a8088a0dbcd15c0e1fd [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d2c801da70cd4a8088a0dbcd15c0e1fd" member_type: VOTER last_known_addr { host: "127.7.40.193" port: 36235 } }
I20260812 06:16:47.267957  7753 leader_election.cc:304] T 7c84d5de902a42d0b36e1dc3e98098fb P d2c801da70cd4a8088a0dbcd15c0e1fd [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: d2c801da70cd4a8088a0dbcd15c0e1fd; no voters: 
I20260812 06:16:47.268107  7753 leader_election.cc:290] T 7c84d5de902a42d0b36e1dc3e98098fb P d2c801da70cd4a8088a0dbcd15c0e1fd [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:47.268232  7755 raft_consensus.cc:2804] T 7c84d5de902a42d0b36e1dc3e98098fb P d2c801da70cd4a8088a0dbcd15c0e1fd [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:47.268481  7753 ts_tablet_manager.cc:1434] T 7c84d5de902a42d0b36e1dc3e98098fb P d2c801da70cd4a8088a0dbcd15c0e1fd: Time spent starting tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:16:47.268527  7755 raft_consensus.cc:697] T 7c84d5de902a42d0b36e1dc3e98098fb P d2c801da70cd4a8088a0dbcd15c0e1fd [term 1 LEADER]: Becoming Leader. State: Replica: d2c801da70cd4a8088a0dbcd15c0e1fd, State: Running, Role: LEADER
I20260812 06:16:47.268527  7739 heartbeater.cc:499] Master 127.7.40.254:37041 was elected leader, sending a full tablet report...
I20260812 06:16:47.268720  7755 consensus_queue.cc:237] T 7c84d5de902a42d0b36e1dc3e98098fb P d2c801da70cd4a8088a0dbcd15c0e1fd [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: "d2c801da70cd4a8088a0dbcd15c0e1fd" member_type: VOTER last_known_addr { host: "127.7.40.193" port: 36235 } }
I20260812 06:16:47.270057  7581 catalog_manager.cc:5719] T 7c84d5de902a42d0b36e1dc3e98098fb P d2c801da70cd4a8088a0dbcd15c0e1fd reported cstate change: term changed from 0 to 1, leader changed from <none> to d2c801da70cd4a8088a0dbcd15c0e1fd (127.7.40.193). New cstate: current_term: 1 leader_uuid: "d2c801da70cd4a8088a0dbcd15c0e1fd" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d2c801da70cd4a8088a0dbcd15c0e1fd" member_type: VOTER last_known_addr { host: "127.7.40.193" port: 36235 } health_report { overall_health: HEALTHY } } }
I20260812 06:16:47.330263  7331 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.053s	user 0.010s	sys 0.012s
I20260812 06:16:47.485571  7740 maintenance_manager.cc:419] P d2c801da70cd4a8088a0dbcd15c0e1fd: Scheduling FlushMRSOp(7c84d5de902a42d0b36e1dc3e98098fb): perf score=19.054940
I20260812 06:16:47.649163  7669 maintenance_manager.cc:643] P d2c801da70cd4a8088a0dbcd15c0e1fd: FlushMRSOp(7c84d5de902a42d0b36e1dc3e98098fb) complete. Timing: real 0.163s	user 0.117s	sys 0.044s Metrics: {"bytes_written":12676708,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":73,"dirs.run_cpu_time_us":224,"dirs.run_wall_time_us":808,"drs_written":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4,"lbm_write_time_us":40958,"lbm_writes_lt_1ms":766,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":11648,"update_count":1545}
I20260812 06:16:47.649802  7740 maintenance_manager.cc:419] P d2c801da70cd4a8088a0dbcd15c0e1fd: Scheduling LogGCOp(7c84d5de902a42d0b36e1dc3e98098fb): free 20743880 bytes of WAL
I20260812 06:16:47.650127  7669 log_reader.cc:385] T 7c84d5de902a42d0b36e1dc3e98098fb: removed 2 log segments from log reader
I20260812 06:16:47.650193  7669 log.cc:1079] T 7c84d5de902a42d0b36e1dc3e98098fb P d2c801da70cd4a8088a0dbcd15c0e1fd: Deleting log segment in path: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401677830-7331-0/minicluster-data/ts-0-root/wals/7c84d5de902a42d0b36e1dc3e98098fb/wal-000000001 (ops 1-6)
I20260812 06:16:47.650269  7669 log.cc:1079] T 7c84d5de902a42d0b36e1dc3e98098fb P d2c801da70cd4a8088a0dbcd15c0e1fd: Deleting log segment in path: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401677830-7331-0/minicluster-data/ts-0-root/wals/7c84d5de902a42d0b36e1dc3e98098fb/wal-000000002 (ops 7-11)
I20260812 06:16:47.654909  7669 maintenance_manager.cc:643] P d2c801da70cd4a8088a0dbcd15c0e1fd: LogGCOp(7c84d5de902a42d0b36e1dc3e98098fb) complete. Timing: real 0.005s	user 0.000s	sys 0.004s Metrics: {}
I20260812 06:16:47.655279  7740 maintenance_manager.cc:419] P d2c801da70cd4a8088a0dbcd15c0e1fd: Scheduling FlushDeltaMemStoresOp(7c84d5de902a42d0b36e1dc3e98098fb): perf score=2.188937
I20260812 06:16:47.671092  7669 maintenance_manager.cc:643] P d2c801da70cd4a8088a0dbcd15c0e1fd: FlushDeltaMemStoresOp(7c84d5de902a42d0b36e1dc3e98098fb) complete. Timing: real 0.016s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3733434,"delete_count":0,"lbm_write_time_us":3634,"lbm_writes_lt_1ms":94,"reinsert_count":0,"update_count":455}
I20260812 06:16:47.671490  7740 maintenance_manager.cc:419] P d2c801da70cd4a8088a0dbcd15c0e1fd: Scheduling FlushDeltaMemStoresOp(7c84d5de902a42d0b36e1dc3e98098fb): perf score=2.188937
I20260812 06:16:47.681548  7669 maintenance_manager.cc:643] P d2c801da70cd4a8088a0dbcd15c0e1fd: FlushDeltaMemStoresOp(7c84d5de902a42d0b36e1dc3e98098fb) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3924,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:47.681998  7740 maintenance_manager.cc:419] P d2c801da70cd4a8088a0dbcd15c0e1fd: Scheduling UndoDeltaBlockGCOp(7c84d5de902a42d0b36e1dc3e98098fb): 16411392 bytes on disk
I20260812 06:16:47.682384  7669 maintenance_manager.cc:643] P d2c801da70cd4a8088a0dbcd15c0e1fd: UndoDeltaBlockGCOp(7c84d5de902a42d0b36e1dc3e98098fb) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4}
I20260812 06:16:47.682747  7740 maintenance_manager.cc:419] P d2c801da70cd4a8088a0dbcd15c0e1fd: Scheduling MajorDeltaCompactionOp(7c84d5de902a42d0b36e1dc3e98098fb): perf score=1.000000
I20260812 06:16:47.868336  7669 maintenance_manager.cc:643] P d2c801da70cd4a8088a0dbcd15c0e1fd: MajorDeltaCompactionOp(7c84d5de902a42d0b36e1dc3e98098fb) complete. Timing: real 0.185s	user 0.108s	sys 0.076s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774801,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":2722,"lbm_read_time_us":13607,"lbm_reads_lt_1ms":569,"lbm_write_time_us":30631,"lbm_writes_lt_1ms":543,"mutex_wait_us":22,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":18944,"thread_start_us":1662,"threads_started":5,"update_count":2500}
I20260812 06:16:47.868995  7740 maintenance_manager.cc:419] P d2c801da70cd4a8088a0dbcd15c0e1fd: Scheduling FlushDeltaMemStoresOp(7c84d5de902a42d0b36e1dc3e98098fb): perf score=14.095187
I20260812 06:16:47.908008  7669 maintenance_manager.cc:643] P d2c801da70cd4a8088a0dbcd15c0e1fd: FlushDeltaMemStoresOp(7c84d5de902a42d0b36e1dc3e98098fb) complete. Timing: real 0.039s	user 0.017s	sys 0.020s Metrics: {"bytes_written":16409899,"delete_count":0,"lbm_write_time_us":17633,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:47.908550  7740 maintenance_manager.cc:419] P d2c801da70cd4a8088a0dbcd15c0e1fd: Scheduling FlushDeltaMemStoresOp(7c84d5de902a42d0b36e1dc3e98098fb): perf score=2.188937
I20260812 06:16:47.926790  7669 maintenance_manager.cc:643] P d2c801da70cd4a8088a0dbcd15c0e1fd: FlushDeltaMemStoresOp(7c84d5de902a42d0b36e1dc3e98098fb) complete. Timing: real 0.018s	user 0.007s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5869,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:47.927387  7740 maintenance_manager.cc:419] P d2c801da70cd4a8088a0dbcd15c0e1fd: Scheduling MajorDeltaCompactionOp(7c84d5de902a42d0b36e1dc3e98098fb): perf score=1.000000
I20260812 06:16:48.085239  7669 maintenance_manager.cc:643] P d2c801da70cd4a8088a0dbcd15c0e1fd: MajorDeltaCompactionOp(7c84d5de902a42d0b36e1dc3e98098fb) complete. Timing: real 0.158s	user 0.118s	sys 0.039s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774686,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":436,"lbm_read_time_us":9466,"lbm_reads_lt_1ms":568,"lbm_write_time_us":29687,"lbm_writes_lt_1ms":543,"mutex_wait_us":26,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11008,"update_count":2500}
I20260812 06:16:48.085954  7740 maintenance_manager.cc:419] P d2c801da70cd4a8088a0dbcd15c0e1fd: Scheduling FlushDeltaMemStoresOp(7c84d5de902a42d0b36e1dc3e98098fb): perf score=14.095187
I20260812 06:16:48.126200  7669 maintenance_manager.cc:643] P d2c801da70cd4a8088a0dbcd15c0e1fd: FlushDeltaMemStoresOp(7c84d5de902a42d0b36e1dc3e98098fb) complete. Timing: real 0.040s	user 0.027s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18539,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:48.126858  7740 maintenance_manager.cc:419] P d2c801da70cd4a8088a0dbcd15c0e1fd: Scheduling MajorDeltaCompactionOp(7c84d5de902a42d0b36e1dc3e98098fb): perf score=1.000000
I20260812 06:16:48.296873  7669 maintenance_manager.cc:643] P d2c801da70cd4a8088a0dbcd15c0e1fd: MajorDeltaCompactionOp(7c84d5de902a42d0b36e1dc3e98098fb) complete. Timing: real 0.170s	user 0.097s	sys 0.065s 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":153,"lbm_read_time_us":10019,"lbm_reads_lt_1ms":467,"lbm_write_time_us":27689,"lbm_writes_lt_1ms":443,"mutex_wait_us":44,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":13312,"update_count":2000}
I20260812 06:16:48.297636  7740 maintenance_manager.cc:419] P d2c801da70cd4a8088a0dbcd15c0e1fd: Scheduling FlushDeltaMemStoresOp(7c84d5de902a42d0b36e1dc3e98098fb): perf score=14.095187
I20260812 06:16:48.343223  7669 maintenance_manager.cc:643] P d2c801da70cd4a8088a0dbcd15c0e1fd: FlushDeltaMemStoresOp(7c84d5de902a42d0b36e1dc3e98098fb) complete. Timing: real 0.045s	user 0.033s	sys 0.011s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19936,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:48.343753  7740 maintenance_manager.cc:419] P d2c801da70cd4a8088a0dbcd15c0e1fd: Scheduling FlushDeltaMemStoresOp(7c84d5de902a42d0b36e1dc3e98098fb): perf score=2.188937
I20260812 06:16:48.355926  7669 maintenance_manager.cc:643] P d2c801da70cd4a8088a0dbcd15c0e1fd: FlushDeltaMemStoresOp(7c84d5de902a42d0b36e1dc3e98098fb) complete. Timing: real 0.012s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4539,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:48.356508  7740 maintenance_manager.cc:419] P d2c801da70cd4a8088a0dbcd15c0e1fd: Scheduling MajorDeltaCompactionOp(7c84d5de902a42d0b36e1dc3e98098fb): perf score=1.000000
I20260812 06:16:48.549983  7669 maintenance_manager.cc:643] P d2c801da70cd4a8088a0dbcd15c0e1fd: MajorDeltaCompactionOp(7c84d5de902a42d0b36e1dc3e98098fb) complete. Timing: real 0.193s	user 0.105s	sys 0.080s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":510,"lbm_read_time_us":15166,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28315,"lbm_writes_lt_1ms":543,"mutex_wait_us":50,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11776,"update_count":2500}
I20260812 06:16:48.550792  7740 maintenance_manager.cc:419] P d2c801da70cd4a8088a0dbcd15c0e1fd: Scheduling FlushDeltaMemStoresOp(7c84d5de902a42d0b36e1dc3e98098fb): perf score=14.095187
I20260812 06:16:48.604041  7669 maintenance_manager.cc:643] P d2c801da70cd4a8088a0dbcd15c0e1fd: FlushDeltaMemStoresOp(7c84d5de902a42d0b36e1dc3e98098fb) complete. Timing: real 0.053s	user 0.031s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22013,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:48.604568  7740 maintenance_manager.cc:419] P d2c801da70cd4a8088a0dbcd15c0e1fd: Scheduling FlushDeltaMemStoresOp(7c84d5de902a42d0b36e1dc3e98098fb): perf score=2.188937
I20260812 06:16:48.615814  7669 maintenance_manager.cc:643] P d2c801da70cd4a8088a0dbcd15c0e1fd: FlushDeltaMemStoresOp(7c84d5de902a42d0b36e1dc3e98098fb) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4210,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:48.616431  7740 maintenance_manager.cc:419] P d2c801da70cd4a8088a0dbcd15c0e1fd: Scheduling MajorDeltaCompactionOp(7c84d5de902a42d0b36e1dc3e98098fb): perf score=1.000000
I20260812 06:16:48.776110  7669 maintenance_manager.cc:643] P d2c801da70cd4a8088a0dbcd15c0e1fd: MajorDeltaCompactionOp(7c84d5de902a42d0b36e1dc3e98098fb) complete. Timing: real 0.159s	user 0.105s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":950,"lbm_read_time_us":11241,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31499,"lbm_writes_lt_1ms":543,"mutex_wait_us":489,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9344,"update_count":2500}
I20260812 06:16:48.776744  7740 maintenance_manager.cc:419] P d2c801da70cd4a8088a0dbcd15c0e1fd: Scheduling FlushDeltaMemStoresOp(7c84d5de902a42d0b36e1dc3e98098fb): perf score=11.118625
I20260812 06:16:48.812390  7669 maintenance_manager.cc:643] P d2c801da70cd4a8088a0dbcd15c0e1fd: FlushDeltaMemStoresOp(7c84d5de902a42d0b36e1dc3e98098fb) complete. Timing: real 0.035s	user 0.021s	sys 0.012s Metrics: {"bytes_written":12635685,"delete_count":0,"lbm_write_time_us":15220,"lbm_writes_lt_1ms":311,"reinsert_count":0,"update_count":1540}
I20260812 06:16:48.812945  7740 maintenance_manager.cc:419] P d2c801da70cd4a8088a0dbcd15c0e1fd: Scheduling FlushDeltaMemStoresOp(7c84d5de902a42d0b36e1dc3e98098fb): perf score=2.188937
I20260812 06:16:48.826704  7669 maintenance_manager.cc:643] P d2c801da70cd4a8088a0dbcd15c0e1fd: FlushDeltaMemStoresOp(7c84d5de902a42d0b36e1dc3e98098fb) complete. Timing: real 0.014s	user 0.008s	sys 0.005s Metrics: {"bytes_written":3774459,"delete_count":0,"lbm_write_time_us":5411,"lbm_writes_lt_1ms":95,"reinsert_count":0,"update_count":460}
I20260812 06:16:48.827199  7740 maintenance_manager.cc:419] P d2c801da70cd4a8088a0dbcd15c0e1fd: Scheduling FlushMRSOp(7c84d5de902a42d0b36e1dc3e98098fb): perf score=1.000000
I20260812 06:16:48.855396  7669 maintenance_manager.cc:643] P d2c801da70cd4a8088a0dbcd15c0e1fd: FlushMRSOp(7c84d5de902a42d0b36e1dc3e98098fb) complete. Timing: real 0.028s	user 0.024s	sys 0.002s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":76,"dirs.run_cpu_time_us":274,"dirs.run_wall_time_us":1346,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1520,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:16:48.855984  7740 maintenance_manager.cc:419] P d2c801da70cd4a8088a0dbcd15c0e1fd: Scheduling LogGCOp(7c84d5de902a42d0b36e1dc3e98098fb): free 112692379 bytes of WAL
I20260812 06:16:48.856231  7669 log_reader.cc:385] T 7c84d5de902a42d0b36e1dc3e98098fb: removed 11 log segments from log reader
I20260812 06:16:48.856277  7669 log.cc:1079] T 7c84d5de902a42d0b36e1dc3e98098fb P d2c801da70cd4a8088a0dbcd15c0e1fd: Deleting log segment in path: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401677830-7331-0/minicluster-data/ts-0-root/wals/7c84d5de902a42d0b36e1dc3e98098fb/wal-000000003 (ops 12-16)
I20260812 06:16:48.856307  7669 log.cc:1079] T 7c84d5de902a42d0b36e1dc3e98098fb P d2c801da70cd4a8088a0dbcd15c0e1fd: Deleting log segment in path: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401677830-7331-0/minicluster-data/ts-0-root/wals/7c84d5de902a42d0b36e1dc3e98098fb/wal-000000004 (ops 17-21)
I20260812 06:16:48.856350  7669 log.cc:1079] T 7c84d5de902a42d0b36e1dc3e98098fb P d2c801da70cd4a8088a0dbcd15c0e1fd: Deleting log segment in path: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401677830-7331-0/minicluster-data/ts-0-root/wals/7c84d5de902a42d0b36e1dc3e98098fb/wal-000000005 (ops 22-26)
I20260812 06:16:48.856393  7669 log.cc:1079] T 7c84d5de902a42d0b36e1dc3e98098fb P d2c801da70cd4a8088a0dbcd15c0e1fd: Deleting log segment in path: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401677830-7331-0/minicluster-data/ts-0-root/wals/7c84d5de902a42d0b36e1dc3e98098fb/wal-000000006 (ops 27-31)
I20260812 06:16:48.856423  7669 log.cc:1079] T 7c84d5de902a42d0b36e1dc3e98098fb P d2c801da70cd4a8088a0dbcd15c0e1fd: Deleting log segment in path: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401677830-7331-0/minicluster-data/ts-0-root/wals/7c84d5de902a42d0b36e1dc3e98098fb/wal-000000007 (ops 32-36)
I20260812 06:16:48.856482  7669 log.cc:1079] T 7c84d5de902a42d0b36e1dc3e98098fb P d2c801da70cd4a8088a0dbcd15c0e1fd: Deleting log segment in path: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401677830-7331-0/minicluster-data/ts-0-root/wals/7c84d5de902a42d0b36e1dc3e98098fb/wal-000000008 (ops 37-41)
I20260812 06:16:48.856521  7669 log.cc:1079] T 7c84d5de902a42d0b36e1dc3e98098fb P d2c801da70cd4a8088a0dbcd15c0e1fd: Deleting log segment in path: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401677830-7331-0/minicluster-data/ts-0-root/wals/7c84d5de902a42d0b36e1dc3e98098fb/wal-000000009 (ops 42-46)
I20260812 06:16:48.856560  7669 log.cc:1079] T 7c84d5de902a42d0b36e1dc3e98098fb P d2c801da70cd4a8088a0dbcd15c0e1fd: Deleting log segment in path: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401677830-7331-0/minicluster-data/ts-0-root/wals/7c84d5de902a42d0b36e1dc3e98098fb/wal-000000010 (ops 47-51)
I20260812 06:16:48.856606  7669 log.cc:1079] T 7c84d5de902a42d0b36e1dc3e98098fb P d2c801da70cd4a8088a0dbcd15c0e1fd: Deleting log segment in path: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401677830-7331-0/minicluster-data/ts-0-root/wals/7c84d5de902a42d0b36e1dc3e98098fb/wal-000000011 (ops 52-56)
I20260812 06:16:48.856649  7669 log.cc:1079] T 7c84d5de902a42d0b36e1dc3e98098fb P d2c801da70cd4a8088a0dbcd15c0e1fd: Deleting log segment in path: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401677830-7331-0/minicluster-data/ts-0-root/wals/7c84d5de902a42d0b36e1dc3e98098fb/wal-000000012 (ops 57-61)
I20260812 06:16:48.856690  7669 log.cc:1079] T 7c84d5de902a42d0b36e1dc3e98098fb P d2c801da70cd4a8088a0dbcd15c0e1fd: Deleting log segment in path: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401677830-7331-0/minicluster-data/ts-0-root/wals/7c84d5de902a42d0b36e1dc3e98098fb/wal-000000013 (ops 62-66)
I20260812 06:16:48.883802  7669 maintenance_manager.cc:643] P d2c801da70cd4a8088a0dbcd15c0e1fd: LogGCOp(7c84d5de902a42d0b36e1dc3e98098fb) complete. Timing: real 0.028s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:16:48.884398  7740 maintenance_manager.cc:419] P d2c801da70cd4a8088a0dbcd15c0e1fd: Scheduling FlushDeltaMemStoresOp(7c84d5de902a42d0b36e1dc3e98098fb): perf score=6.157687
I20260812 06:16:48.905072  7669 maintenance_manager.cc:643] P d2c801da70cd4a8088a0dbcd15c0e1fd: FlushDeltaMemStoresOp(7c84d5de902a42d0b36e1dc3e98098fb) complete. Timing: real 0.020s	user 0.001s	sys 0.016s Metrics: {"bytes_written":7630738,"delete_count":0,"lbm_write_time_us":8221,"lbm_writes_lt_1ms":189,"reinsert_count":0,"update_count":930}
I20260812 06:16:48.905579  7740 maintenance_manager.cc:419] P d2c801da70cd4a8088a0dbcd15c0e1fd: Scheduling MajorDeltaCompactionOp(7c84d5de902a42d0b36e1dc3e98098fb): perf score=1.000000
I20260812 06:16:49.117378  7669 maintenance_manager.cc:643] P d2c801da70cd4a8088a0dbcd15c0e1fd: MajorDeltaCompactionOp(7c84d5de902a42d0b36e1dc3e98098fb) complete. Timing: real 0.211s	user 0.140s	sys 0.065s Metrics: {"cfile_cache_miss":619,"cfile_cache_miss_bytes":28302876,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":590,"lbm_read_time_us":13215,"lbm_reads_lt_1ms":651,"lbm_write_time_us":36567,"lbm_writes_lt_1ms":629,"mutex_wait_us":273,"peak_mem_usage":72887214,"reinsert_count":0,"spinlock_wait_cycles":15744,"thread_start_us":81,"threads_started":1,"update_count":2930}
I20260812 06:16:49.118034  7740 maintenance_manager.cc:419] P d2c801da70cd4a8088a0dbcd15c0e1fd: Scheduling FlushDeltaMemStoresOp(7c84d5de902a42d0b36e1dc3e98098fb): perf score=15.087375
I20260812 06:16:49.173609  7669 maintenance_manager.cc:643] P d2c801da70cd4a8088a0dbcd15c0e1fd: FlushDeltaMemStoresOp(7c84d5de902a42d0b36e1dc3e98098fb) complete. Timing: real 0.055s	user 0.023s	sys 0.029s Metrics: {"bytes_written":16984243,"delete_count":0,"lbm_write_time_us":22758,"lbm_writes_lt_1ms":417,"reinsert_count":0,"update_count":2070}
I20260812 06:16:49.174249  7740 maintenance_manager.cc:419] P d2c801da70cd4a8088a0dbcd15c0e1fd: Scheduling FlushDeltaMemStoresOp(7c84d5de902a42d0b36e1dc3e98098fb): perf score=2.188937
I20260812 06:16:49.207824  7669 maintenance_manager.cc:643] P d2c801da70cd4a8088a0dbcd15c0e1fd: FlushDeltaMemStoresOp(7c84d5de902a42d0b36e1dc3e98098fb) complete. Timing: real 0.033s	user 0.003s	sys 0.024s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6441,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:49.208352  7740 maintenance_manager.cc:419] P d2c801da70cd4a8088a0dbcd15c0e1fd: Scheduling FlushDeltaMemStoresOp(7c84d5de902a42d0b36e1dc3e98098fb): perf score=2.188937
I20260812 06:16:49.220059  7669 maintenance_manager.cc:643] P d2c801da70cd4a8088a0dbcd15c0e1fd: FlushDeltaMemStoresOp(7c84d5de902a42d0b36e1dc3e98098fb) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4619,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:49.220597  7740 maintenance_manager.cc:419] P d2c801da70cd4a8088a0dbcd15c0e1fd: Scheduling UndoDeltaBlockGCOp(7c84d5de902a42d0b36e1dc3e98098fb): 448 bytes on disk
I20260812 06:16:49.221041  7669 maintenance_manager.cc:643] P d2c801da70cd4a8088a0dbcd15c0e1fd: UndoDeltaBlockGCOp(7c84d5de902a42d0b36e1dc3e98098fb) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":57,"lbm_reads_lt_1ms":4}
I20260812 06:16:49.221526  7740 maintenance_manager.cc:419] P d2c801da70cd4a8088a0dbcd15c0e1fd: Scheduling MajorDeltaCompactionOp(7c84d5de902a42d0b36e1dc3e98098fb): perf score=1.000000
I20260812 06:16:49.457991  7669 maintenance_manager.cc:643] P d2c801da70cd4a8088a0dbcd15c0e1fd: MajorDeltaCompactionOp(7c84d5de902a42d0b36e1dc3e98098fb) complete. Timing: real 0.236s	user 0.134s	sys 0.090s Metrics: {"cfile_cache_miss":647,"cfile_cache_miss_bytes":29451561,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":222,"lbm_read_time_us":15507,"lbm_reads_lt_1ms":687,"lbm_write_time_us":37455,"lbm_writes_lt_1ms":657,"mutex_wait_us":45,"peak_mem_usage":77157346,"reinsert_count":0,"spinlock_wait_cycles":7936,"update_count":3070}
I20260812 06:16:49.458726  7740 maintenance_manager.cc:419] P d2c801da70cd4a8088a0dbcd15c0e1fd: Scheduling FlushDeltaMemStoresOp(7c84d5de902a42d0b36e1dc3e98098fb): perf score=18.063937
I20260812 06:16:49.534861  7669 maintenance_manager.cc:643] P d2c801da70cd4a8088a0dbcd15c0e1fd: FlushDeltaMemStoresOp(7c84d5de902a42d0b36e1dc3e98098fb) complete. Timing: real 0.076s	user 0.041s	sys 0.031s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":29662,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:16:49.535408  7740 maintenance_manager.cc:419] P d2c801da70cd4a8088a0dbcd15c0e1fd: Scheduling FlushDeltaMemStoresOp(7c84d5de902a42d0b36e1dc3e98098fb): perf score=2.188937
I20260812 06:16:49.546136  7669 maintenance_manager.cc:643] P d2c801da70cd4a8088a0dbcd15c0e1fd: FlushDeltaMemStoresOp(7c84d5de902a42d0b36e1dc3e98098fb) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4220,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:49.546718  7740 maintenance_manager.cc:419] P d2c801da70cd4a8088a0dbcd15c0e1fd: Scheduling MajorDeltaCompactionOp(7c84d5de902a42d0b36e1dc3e98098fb): perf score=1.000000
I20260812 06:16:49.743821  7669 maintenance_manager.cc:643] P d2c801da70cd4a8088a0dbcd15c0e1fd: MajorDeltaCompactionOp(7c84d5de902a42d0b36e1dc3e98098fb) complete. Timing: real 0.197s	user 0.137s	sys 0.060s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877103,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":232,"lbm_read_time_us":14814,"lbm_reads_lt_1ms":672,"lbm_write_time_us":33862,"lbm_writes_lt_1ms":643,"mutex_wait_us":56,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":3000}
I20260812 06:16:49.744571  7740 maintenance_manager.cc:419] P d2c801da70cd4a8088a0dbcd15c0e1fd: Scheduling FlushDeltaMemStoresOp(7c84d5de902a42d0b36e1dc3e98098fb): perf score=14.095187
I20260812 06:16:49.797127  7669 maintenance_manager.cc:643] P d2c801da70cd4a8088a0dbcd15c0e1fd: FlushDeltaMemStoresOp(7c84d5de902a42d0b36e1dc3e98098fb) complete. Timing: real 0.052s	user 0.019s	sys 0.026s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":22083,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:49.797686  7740 maintenance_manager.cc:419] P d2c801da70cd4a8088a0dbcd15c0e1fd: Scheduling FlushDeltaMemStoresOp(7c84d5de902a42d0b36e1dc3e98098fb): perf score=2.188937
I20260812 06:16:49.813594  7669 maintenance_manager.cc:643] P d2c801da70cd4a8088a0dbcd15c0e1fd: FlushDeltaMemStoresOp(7c84d5de902a42d0b36e1dc3e98098fb) complete. Timing: real 0.016s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6135,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:49.814209  7740 maintenance_manager.cc:419] P d2c801da70cd4a8088a0dbcd15c0e1fd: Scheduling MajorDeltaCompactionOp(7c84d5de902a42d0b36e1dc3e98098fb): perf score=1.000000
I20260812 06:16:50.005990  7669 maintenance_manager.cc:643] P d2c801da70cd4a8088a0dbcd15c0e1fd: MajorDeltaCompactionOp(7c84d5de902a42d0b36e1dc3e98098fb) complete. Timing: real 0.192s	user 0.137s	sys 0.053s 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":212,"lbm_read_time_us":14046,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32053,"lbm_writes_lt_1ms":543,"mutex_wait_us":22,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12544,"update_count":2500}
I20260812 06:16:50.006717  7740 maintenance_manager.cc:419] P d2c801da70cd4a8088a0dbcd15c0e1fd: Scheduling FlushDeltaMemStoresOp(7c84d5de902a42d0b36e1dc3e98098fb): perf score=14.095187
I20260812 06:16:50.072544  7669 maintenance_manager.cc:643] P d2c801da70cd4a8088a0dbcd15c0e1fd: FlushDeltaMemStoresOp(7c84d5de902a42d0b36e1dc3e98098fb) complete. Timing: real 0.066s	user 0.036s	sys 0.027s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":24078,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:50.073261  7740 maintenance_manager.cc:419] P d2c801da70cd4a8088a0dbcd15c0e1fd: Scheduling FlushDeltaMemStoresOp(7c84d5de902a42d0b36e1dc3e98098fb): perf score=2.188937
I20260812 06:16:50.091490  7669 maintenance_manager.cc:643] P d2c801da70cd4a8088a0dbcd15c0e1fd: FlushDeltaMemStoresOp(7c84d5de902a42d0b36e1dc3e98098fb) complete. Timing: real 0.018s	user 0.012s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6865,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:50.093482  7740 maintenance_manager.cc:419] P d2c801da70cd4a8088a0dbcd15c0e1fd: Scheduling MajorDeltaCompactionOp(7c84d5de902a42d0b36e1dc3e98098fb): perf score=1.000000
I20260812 06:16:50.288839  7669 maintenance_manager.cc:643] P d2c801da70cd4a8088a0dbcd15c0e1fd: MajorDeltaCompactionOp(7c84d5de902a42d0b36e1dc3e98098fb) complete. Timing: real 0.195s	user 0.123s	sys 0.071s 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":217,"lbm_read_time_us":13889,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31593,"lbm_writes_lt_1ms":543,"mutex_wait_us":51,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":24064,"update_count":2500}
I20260812 06:16:50.289494  7740 maintenance_manager.cc:419] P d2c801da70cd4a8088a0dbcd15c0e1fd: Scheduling FlushDeltaMemStoresOp(7c84d5de902a42d0b36e1dc3e98098fb): perf score=14.095187
I20260812 06:16:50.346875  7669 maintenance_manager.cc:643] P d2c801da70cd4a8088a0dbcd15c0e1fd: FlushDeltaMemStoresOp(7c84d5de902a42d0b36e1dc3e98098fb) complete. Timing: real 0.057s	user 0.032s	sys 0.024s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20742,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:50.347455  7740 maintenance_manager.cc:419] P d2c801da70cd4a8088a0dbcd15c0e1fd: Scheduling FlushDeltaMemStoresOp(7c84d5de902a42d0b36e1dc3e98098fb): perf score=2.188937
I20260812 06:16:50.358378  7669 maintenance_manager.cc:643] P d2c801da70cd4a8088a0dbcd15c0e1fd: FlushDeltaMemStoresOp(7c84d5de902a42d0b36e1dc3e98098fb) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4237,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:50.358884  7740 maintenance_manager.cc:419] P d2c801da70cd4a8088a0dbcd15c0e1fd: Scheduling FlushMRSOp(7c84d5de902a42d0b36e1dc3e98098fb): perf score=1.000000
I20260812 06:16:50.401150  7669 maintenance_manager.cc:643] P d2c801da70cd4a8088a0dbcd15c0e1fd: FlushMRSOp(7c84d5de902a42d0b36e1dc3e98098fb) complete. Timing: real 0.042s	user 0.027s	sys 0.004s Metrics: {"bytes_written":1193509,"cfile_init":1,"dirs.queue_time_us":140,"dirs.run_cpu_time_us":202,"dirs.run_wall_time_us":1318,"drs_written":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2147,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:16:50.401842  7740 maintenance_manager.cc:419] P d2c801da70cd4a8088a0dbcd15c0e1fd: Scheduling LogGCOp(7c84d5de902a42d0b36e1dc3e98098fb): free 124257255 bytes of WAL
I20260812 06:16:50.402074  7669 log_reader.cc:385] T 7c84d5de902a42d0b36e1dc3e98098fb: removed 12 log segments from log reader
I20260812 06:16:50.402137  7669 log.cc:1079] T 7c84d5de902a42d0b36e1dc3e98098fb P d2c801da70cd4a8088a0dbcd15c0e1fd: Deleting log segment in path: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401677830-7331-0/minicluster-data/ts-0-root/wals/7c84d5de902a42d0b36e1dc3e98098fb/wal-000000014 (ops 67-70)
I20260812 06:16:50.402194  7669 log.cc:1079] T 7c84d5de902a42d0b36e1dc3e98098fb P d2c801da70cd4a8088a0dbcd15c0e1fd: Deleting log segment in path: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401677830-7331-0/minicluster-data/ts-0-root/wals/7c84d5de902a42d0b36e1dc3e98098fb/wal-000000015 (ops 71-75)
I20260812 06:16:50.402258  7669 log.cc:1079] T 7c84d5de902a42d0b36e1dc3e98098fb P d2c801da70cd4a8088a0dbcd15c0e1fd: Deleting log segment in path: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401677830-7331-0/minicluster-data/ts-0-root/wals/7c84d5de902a42d0b36e1dc3e98098fb/wal-000000016 (ops 76-80)
I20260812 06:16:50.402302  7669 log.cc:1079] T 7c84d5de902a42d0b36e1dc3e98098fb P d2c801da70cd4a8088a0dbcd15c0e1fd: Deleting log segment in path: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401677830-7331-0/minicluster-data/ts-0-root/wals/7c84d5de902a42d0b36e1dc3e98098fb/wal-000000017 (ops 81-85)
I20260812 06:16:50.402340  7669 log.cc:1079] T 7c84d5de902a42d0b36e1dc3e98098fb P d2c801da70cd4a8088a0dbcd15c0e1fd: Deleting log segment in path: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401677830-7331-0/minicluster-data/ts-0-root/wals/7c84d5de902a42d0b36e1dc3e98098fb/wal-000000018 (ops 86-90)
I20260812 06:16:50.402377  7669 log.cc:1079] T 7c84d5de902a42d0b36e1dc3e98098fb P d2c801da70cd4a8088a0dbcd15c0e1fd: Deleting log segment in path: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401677830-7331-0/minicluster-data/ts-0-root/wals/7c84d5de902a42d0b36e1dc3e98098fb/wal-000000019 (ops 91-95)
I20260812 06:16:50.402416  7669 log.cc:1079] T 7c84d5de902a42d0b36e1dc3e98098fb P d2c801da70cd4a8088a0dbcd15c0e1fd: Deleting log segment in path: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401677830-7331-0/minicluster-data/ts-0-root/wals/7c84d5de902a42d0b36e1dc3e98098fb/wal-000000020 (ops 96-100)
I20260812 06:16:50.402454  7669 log.cc:1079] T 7c84d5de902a42d0b36e1dc3e98098fb P d2c801da70cd4a8088a0dbcd15c0e1fd: Deleting log segment in path: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401677830-7331-0/minicluster-data/ts-0-root/wals/7c84d5de902a42d0b36e1dc3e98098fb/wal-000000021 (ops 101-105)
I20260812 06:16:50.402491  7669 log.cc:1079] T 7c84d5de902a42d0b36e1dc3e98098fb P d2c801da70cd4a8088a0dbcd15c0e1fd: Deleting log segment in path: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401677830-7331-0/minicluster-data/ts-0-root/wals/7c84d5de902a42d0b36e1dc3e98098fb/wal-000000022 (ops 106-110)
I20260812 06:16:50.402530  7669 log.cc:1079] T 7c84d5de902a42d0b36e1dc3e98098fb P d2c801da70cd4a8088a0dbcd15c0e1fd: Deleting log segment in path: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401677830-7331-0/minicluster-data/ts-0-root/wals/7c84d5de902a42d0b36e1dc3e98098fb/wal-000000023 (ops 111-115)
I20260812 06:16:50.402570  7669 log.cc:1079] T 7c84d5de902a42d0b36e1dc3e98098fb P d2c801da70cd4a8088a0dbcd15c0e1fd: Deleting log segment in path: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401677830-7331-0/minicluster-data/ts-0-root/wals/7c84d5de902a42d0b36e1dc3e98098fb/wal-000000024 (ops 116-120)
I20260812 06:16:50.402608  7669 log.cc:1079] T 7c84d5de902a42d0b36e1dc3e98098fb P d2c801da70cd4a8088a0dbcd15c0e1fd: Deleting log segment in path: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401677830-7331-0/minicluster-data/ts-0-root/wals/7c84d5de902a42d0b36e1dc3e98098fb/wal-000000025 (ops 121-125)
I20260812 06:16:50.429610  7669 maintenance_manager.cc:643] P d2c801da70cd4a8088a0dbcd15c0e1fd: LogGCOp(7c84d5de902a42d0b36e1dc3e98098fb) complete. Timing: real 0.028s	user 0.000s	sys 0.024s Metrics: {}
I20260812 06:16:50.430195  7740 maintenance_manager.cc:419] P d2c801da70cd4a8088a0dbcd15c0e1fd: Scheduling FlushDeltaMemStoresOp(7c84d5de902a42d0b36e1dc3e98098fb): perf score=2.188937
I20260812 06:16:50.447129  7669 maintenance_manager.cc:643] P d2c801da70cd4a8088a0dbcd15c0e1fd: FlushDeltaMemStoresOp(7c84d5de902a42d0b36e1dc3e98098fb) complete. Timing: real 0.017s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4211,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:50.447582  7740 maintenance_manager.cc:419] P d2c801da70cd4a8088a0dbcd15c0e1fd: Scheduling UndoDeltaBlockGCOp(7c84d5de902a42d0b36e1dc3e98098fb): 462 bytes on disk
I20260812 06:16:50.447964  7669 maintenance_manager.cc:643] P d2c801da70cd4a8088a0dbcd15c0e1fd: UndoDeltaBlockGCOp(7c84d5de902a42d0b36e1dc3e98098fb) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4}
I20260812 06:16:50.448416  7740 maintenance_manager.cc:419] P d2c801da70cd4a8088a0dbcd15c0e1fd: Scheduling FlushDeltaMemStoresOp(7c84d5de902a42d0b36e1dc3e98098fb): perf score=2.188937
I20260812 06:16:50.459076  7669 maintenance_manager.cc:643] P d2c801da70cd4a8088a0dbcd15c0e1fd: FlushDeltaMemStoresOp(7c84d5de902a42d0b36e1dc3e98098fb) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4194,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:50.459503  7740 maintenance_manager.cc:419] P d2c801da70cd4a8088a0dbcd15c0e1fd: Scheduling MajorDeltaCompactionOp(7c84d5de902a42d0b36e1dc3e98098fb): perf score=1.000000
I20260812 06:16:50.685696  7669 maintenance_manager.cc:643] P d2c801da70cd4a8088a0dbcd15c0e1fd: MajorDeltaCompactionOp(7c84d5de902a42d0b36e1dc3e98098fb) complete. Timing: real 0.226s	user 0.143s	sys 0.080s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979750,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":586,"lbm_read_time_us":15707,"lbm_reads_lt_1ms":774,"lbm_write_time_us":39537,"lbm_writes_lt_1ms":743,"mutex_wait_us":28,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":14336,"thread_start_us":88,"threads_started":1,"update_count":3500}
I20260812 06:16:50.686278  7740 maintenance_manager.cc:419] P d2c801da70cd4a8088a0dbcd15c0e1fd: Scheduling FlushDeltaMemStoresOp(7c84d5de902a42d0b36e1dc3e98098fb): perf score=18.063937
I20260812 06:16:50.743979  7669 maintenance_manager.cc:643] P d2c801da70cd4a8088a0dbcd15c0e1fd: FlushDeltaMemStoresOp(7c84d5de902a42d0b36e1dc3e98098fb) complete. Timing: real 0.058s	user 0.032s	sys 0.023s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":26449,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:16:50.744532  7740 maintenance_manager.cc:419] P d2c801da70cd4a8088a0dbcd15c0e1fd: Scheduling FlushDeltaMemStoresOp(7c84d5de902a42d0b36e1dc3e98098fb): perf score=2.188937
I20260812 06:16:50.756906  7669 maintenance_manager.cc:643] P d2c801da70cd4a8088a0dbcd15c0e1fd: FlushDeltaMemStoresOp(7c84d5de902a42d0b36e1dc3e98098fb) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4855,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:50.758297  7740 maintenance_manager.cc:419] P d2c801da70cd4a8088a0dbcd15c0e1fd: Scheduling MajorDeltaCompactionOp(7c84d5de902a42d0b36e1dc3e98098fb): perf score=1.000000
I20260812 06:16:50.969735  7669 maintenance_manager.cc:643] P d2c801da70cd4a8088a0dbcd15c0e1fd: MajorDeltaCompactionOp(7c84d5de902a42d0b36e1dc3e98098fb) complete. Timing: real 0.211s	user 0.150s	sys 0.057s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877103,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":268,"lbm_read_time_us":15065,"lbm_reads_lt_1ms":672,"lbm_write_time_us":36839,"lbm_writes_lt_1ms":643,"mutex_wait_us":30,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":9088,"update_count":3000}
I20260812 06:16:50.970468  7740 maintenance_manager.cc:419] P d2c801da70cd4a8088a0dbcd15c0e1fd: Scheduling FlushDeltaMemStoresOp(7c84d5de902a42d0b36e1dc3e98098fb): perf score=15.087375
I20260812 06:16:51.015553  7669 maintenance_manager.cc:643] P d2c801da70cd4a8088a0dbcd15c0e1fd: FlushDeltaMemStoresOp(7c84d5de902a42d0b36e1dc3e98098fb) complete. Timing: real 0.045s	user 0.029s	sys 0.014s Metrics: {"bytes_written":16820142,"delete_count":0,"lbm_write_time_us":19471,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:16:51.016716  7740 maintenance_manager.cc:419] P d2c801da70cd4a8088a0dbcd15c0e1fd: Scheduling FlushDeltaMemStoresOp(7c84d5de902a42d0b36e1dc3e98098fb): perf score=2.188937
I20260812 06:16:51.030951  7669 maintenance_manager.cc:643] P d2c801da70cd4a8088a0dbcd15c0e1fd: FlushDeltaMemStoresOp(7c84d5de902a42d0b36e1dc3e98098fb) complete. Timing: real 0.014s	user 0.009s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5254,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:51.031428  7740 maintenance_manager.cc:419] P d2c801da70cd4a8088a0dbcd15c0e1fd: Scheduling MajorDeltaCompactionOp(7c84d5de902a42d0b36e1dc3e98098fb): perf score=1.000000
I20260812 06:16:51.212074  7669 maintenance_manager.cc:643] P d2c801da70cd4a8088a0dbcd15c0e1fd: MajorDeltaCompactionOp(7c84d5de902a42d0b36e1dc3e98098fb) complete. Timing: real 0.180s	user 0.107s	sys 0.051s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774675,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":687,"lbm_read_time_us":10854,"lbm_reads_lt_1ms":568,"lbm_write_time_us":28448,"lbm_writes_lt_1ms":543,"mutex_wait_us":86,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12800,"update_count":2500}
I20260812 06:16:51.212903  7740 maintenance_manager.cc:419] P d2c801da70cd4a8088a0dbcd15c0e1fd: Scheduling FlushDeltaMemStoresOp(7c84d5de902a42d0b36e1dc3e98098fb): perf score=14.095187
I20260812 06:16:51.294660  7669 maintenance_manager.cc:643] P d2c801da70cd4a8088a0dbcd15c0e1fd: FlushDeltaMemStoresOp(7c84d5de902a42d0b36e1dc3e98098fb) complete. Timing: real 0.081s	user 0.034s	sys 0.017s Metrics: {"bytes_written":16409897,"delete_count":0,"lbm_write_time_us":24558,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:16:51.295200  7740 maintenance_manager.cc:419] P d2c801da70cd4a8088a0dbcd15c0e1fd: Scheduling FlushDeltaMemStoresOp(7c84d5de902a42d0b36e1dc3e98098fb): perf score=2.188937
I20260812 06:16:51.310585  7669 maintenance_manager.cc:643] P d2c801da70cd4a8088a0dbcd15c0e1fd: FlushDeltaMemStoresOp(7c84d5de902a42d0b36e1dc3e98098fb) complete. Timing: real 0.015s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5831,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:51.311127  7740 maintenance_manager.cc:419] P d2c801da70cd4a8088a0dbcd15c0e1fd: Scheduling MajorDeltaCompactionOp(7c84d5de902a42d0b36e1dc3e98098fb): perf score=1.000000
I20260812 06:16:51.488036  7669 maintenance_manager.cc:643] P d2c801da70cd4a8088a0dbcd15c0e1fd: MajorDeltaCompactionOp(7c84d5de902a42d0b36e1dc3e98098fb) complete. Timing: real 0.177s	user 0.116s	sys 0.058s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":264,"lbm_read_time_us":13435,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28904,"lbm_writes_lt_1ms":543,"mutex_wait_us":44,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14720,"update_count":2500}
I20260812 06:16:51.488785  7740 maintenance_manager.cc:419] P d2c801da70cd4a8088a0dbcd15c0e1fd: Scheduling FlushDeltaMemStoresOp(7c84d5de902a42d0b36e1dc3e98098fb): perf score=10.126437
I20260812 06:16:51.557340  7669 maintenance_manager.cc:643] P d2c801da70cd4a8088a0dbcd15c0e1fd: FlushDeltaMemStoresOp(7c84d5de902a42d0b36e1dc3e98098fb) complete. Timing: real 0.067s	user 0.024s	sys 0.028s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19654,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:51.558161  7740 maintenance_manager.cc:419] P d2c801da70cd4a8088a0dbcd15c0e1fd: Scheduling FlushDeltaMemStoresOp(7c84d5de902a42d0b36e1dc3e98098fb): perf score=2.188937
I20260812 06:16:51.569041  7669 maintenance_manager.cc:643] P d2c801da70cd4a8088a0dbcd15c0e1fd: FlushDeltaMemStoresOp(7c84d5de902a42d0b36e1dc3e98098fb) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4209,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:51.569670  7740 maintenance_manager.cc:419] P d2c801da70cd4a8088a0dbcd15c0e1fd: Scheduling MajorDeltaCompactionOp(7c84d5de902a42d0b36e1dc3e98098fb): perf score=1.000000
I20260812 06:16:51.766047  7669 maintenance_manager.cc:643] P d2c801da70cd4a8088a0dbcd15c0e1fd: MajorDeltaCompactionOp(7c84d5de902a42d0b36e1dc3e98098fb) complete. Timing: real 0.196s	user 0.134s	sys 0.053s 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":4743,"lbm_read_time_us":12546,"lbm_reads_lt_1ms":472,"lbm_write_time_us":30670,"lbm_writes_lt_1ms":443,"mutex_wait_us":3547,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":15488,"update_count":2000}
I20260812 06:16:51.766645  7740 maintenance_manager.cc:419] P d2c801da70cd4a8088a0dbcd15c0e1fd: Scheduling FlushDeltaMemStoresOp(7c84d5de902a42d0b36e1dc3e98098fb): perf score=10.126437
I20260812 06:16:51.813966  7669 maintenance_manager.cc:643] P d2c801da70cd4a8088a0dbcd15c0e1fd: FlushDeltaMemStoresOp(7c84d5de902a42d0b36e1dc3e98098fb) complete. Timing: real 0.047s	user 0.019s	sys 0.019s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":17828,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:51.814422  7740 maintenance_manager.cc:419] P d2c801da70cd4a8088a0dbcd15c0e1fd: Scheduling FlushDeltaMemStoresOp(7c84d5de902a42d0b36e1dc3e98098fb): perf score=2.188937
I20260812 06:16:51.825379  7669 maintenance_manager.cc:643] P d2c801da70cd4a8088a0dbcd15c0e1fd: FlushDeltaMemStoresOp(7c84d5de902a42d0b36e1dc3e98098fb) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3984,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:51.826234  7740 maintenance_manager.cc:419] P d2c801da70cd4a8088a0dbcd15c0e1fd: Scheduling MajorDeltaCompactionOp(7c84d5de902a42d0b36e1dc3e98098fb): perf score=1.000000
I20260812 06:16:51.954368  7669 maintenance_manager.cc:643] P d2c801da70cd4a8088a0dbcd15c0e1fd: MajorDeltaCompactionOp(7c84d5de902a42d0b36e1dc3e98098fb) complete. Timing: real 0.128s	user 0.103s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672280,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":332,"lbm_read_time_us":9206,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24268,"lbm_writes_lt_1ms":443,"mutex_wait_us":119,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":13312,"update_count":2000}
I20260812 06:16:51.955156  7740 maintenance_manager.cc:419] P d2c801da70cd4a8088a0dbcd15c0e1fd: Scheduling FlushDeltaMemStoresOp(7c84d5de902a42d0b36e1dc3e98098fb): perf score=10.126437
I20260812 06:16:51.991365  7669 maintenance_manager.cc:643] P d2c801da70cd4a8088a0dbcd15c0e1fd: FlushDeltaMemStoresOp(7c84d5de902a42d0b36e1dc3e98098fb) complete. Timing: real 0.036s	user 0.022s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15173,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:51.991854  7740 maintenance_manager.cc:419] P d2c801da70cd4a8088a0dbcd15c0e1fd: Scheduling FlushDeltaMemStoresOp(7c84d5de902a42d0b36e1dc3e98098fb): perf score=2.188937
I20260812 06:16:52.002367  7669 maintenance_manager.cc:643] P d2c801da70cd4a8088a0dbcd15c0e1fd: FlushDeltaMemStoresOp(7c84d5de902a42d0b36e1dc3e98098fb) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4052,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:52.002827  7740 maintenance_manager.cc:419] P d2c801da70cd4a8088a0dbcd15c0e1fd: Scheduling FlushMRSOp(7c84d5de902a42d0b36e1dc3e98098fb): perf score=1.000000
I20260812 06:16:52.040853  7669 maintenance_manager.cc:643] P d2c801da70cd4a8088a0dbcd15c0e1fd: FlushMRSOp(7c84d5de902a42d0b36e1dc3e98098fb) complete. Timing: real 0.038s	user 0.036s	sys 0.000s Metrics: {"bytes_written":1234475,"cfile_init":1,"dirs.queue_time_us":78,"dirs.run_cpu_time_us":210,"dirs.run_wall_time_us":1426,"drs_written":1,"lbm_read_time_us":48,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1558,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30,"spinlock_wait_cycles":896}
I20260812 06:16:52.041805  7740 maintenance_manager.cc:419] P d2c801da70cd4a8088a0dbcd15c0e1fd: Scheduling LogGCOp(7c84d5de902a42d0b36e1dc3e98098fb): free 120553572 bytes of WAL
I20260812 06:16:52.042171  7669 log_reader.cc:385] T 7c84d5de902a42d0b36e1dc3e98098fb: removed 12 log segments from log reader
I20260812 06:16:52.042255  7669 log.cc:1079] T 7c84d5de902a42d0b36e1dc3e98098fb P d2c801da70cd4a8088a0dbcd15c0e1fd: Deleting log segment in path: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401677830-7331-0/minicluster-data/ts-0-root/wals/7c84d5de902a42d0b36e1dc3e98098fb/wal-000000026 (ops 126-130)
I20260812 06:16:52.042325  7669 log.cc:1079] T 7c84d5de902a42d0b36e1dc3e98098fb P d2c801da70cd4a8088a0dbcd15c0e1fd: Deleting log segment in path: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401677830-7331-0/minicluster-data/ts-0-root/wals/7c84d5de902a42d0b36e1dc3e98098fb/wal-000000027 (ops 131-135)
I20260812 06:16:52.042389  7669 log.cc:1079] T 7c84d5de902a42d0b36e1dc3e98098fb P d2c801da70cd4a8088a0dbcd15c0e1fd: Deleting log segment in path: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401677830-7331-0/minicluster-data/ts-0-root/wals/7c84d5de902a42d0b36e1dc3e98098fb/wal-000000028 (ops 136-140)
I20260812 06:16:52.042435  7669 log.cc:1079] T 7c84d5de902a42d0b36e1dc3e98098fb P d2c801da70cd4a8088a0dbcd15c0e1fd: Deleting log segment in path: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401677830-7331-0/minicluster-data/ts-0-root/wals/7c84d5de902a42d0b36e1dc3e98098fb/wal-000000029 (ops 141-145)
I20260812 06:16:52.042479  7669 log.cc:1079] T 7c84d5de902a42d0b36e1dc3e98098fb P d2c801da70cd4a8088a0dbcd15c0e1fd: Deleting log segment in path: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401677830-7331-0/minicluster-data/ts-0-root/wals/7c84d5de902a42d0b36e1dc3e98098fb/wal-000000030 (ops 146-150)
I20260812 06:16:52.042520  7669 log.cc:1079] T 7c84d5de902a42d0b36e1dc3e98098fb P d2c801da70cd4a8088a0dbcd15c0e1fd: Deleting log segment in path: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401677830-7331-0/minicluster-data/ts-0-root/wals/7c84d5de902a42d0b36e1dc3e98098fb/wal-000000031 (ops 151-154)
I20260812 06:16:52.042563  7669 log.cc:1079] T 7c84d5de902a42d0b36e1dc3e98098fb P d2c801da70cd4a8088a0dbcd15c0e1fd: Deleting log segment in path: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401677830-7331-0/minicluster-data/ts-0-root/wals/7c84d5de902a42d0b36e1dc3e98098fb/wal-000000032 (ops 155-159)
I20260812 06:16:52.042613  7669 log.cc:1079] T 7c84d5de902a42d0b36e1dc3e98098fb P d2c801da70cd4a8088a0dbcd15c0e1fd: Deleting log segment in path: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401677830-7331-0/minicluster-data/ts-0-root/wals/7c84d5de902a42d0b36e1dc3e98098fb/wal-000000033 (ops 160-164)
I20260812 06:16:52.042654  7669 log.cc:1079] T 7c84d5de902a42d0b36e1dc3e98098fb P d2c801da70cd4a8088a0dbcd15c0e1fd: Deleting log segment in path: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401677830-7331-0/minicluster-data/ts-0-root/wals/7c84d5de902a42d0b36e1dc3e98098fb/wal-000000034 (ops 165-169)
I20260812 06:16:52.042697  7669 log.cc:1079] T 7c84d5de902a42d0b36e1dc3e98098fb P d2c801da70cd4a8088a0dbcd15c0e1fd: Deleting log segment in path: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401677830-7331-0/minicluster-data/ts-0-root/wals/7c84d5de902a42d0b36e1dc3e98098fb/wal-000000035 (ops 170-174)
I20260812 06:16:52.042739  7669 log.cc:1079] T 7c84d5de902a42d0b36e1dc3e98098fb P d2c801da70cd4a8088a0dbcd15c0e1fd: Deleting log segment in path: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401677830-7331-0/minicluster-data/ts-0-root/wals/7c84d5de902a42d0b36e1dc3e98098fb/wal-000000036 (ops 175-178)
I20260812 06:16:52.042780  7669 log.cc:1079] T 7c84d5de902a42d0b36e1dc3e98098fb P d2c801da70cd4a8088a0dbcd15c0e1fd: Deleting log segment in path: /tmp/dist-test-taskkYbHeh/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515401677830-7331-0/minicluster-data/ts-0-root/wals/7c84d5de902a42d0b36e1dc3e98098fb/wal-000000037 (ops 179-183)
I20260812 06:16:52.074491  7669 maintenance_manager.cc:643] P d2c801da70cd4a8088a0dbcd15c0e1fd: LogGCOp(7c84d5de902a42d0b36e1dc3e98098fb) complete. Timing: real 0.032s	user 0.000s	sys 0.032s Metrics: {}
I20260812 06:16:52.074994  7740 maintenance_manager.cc:419] P d2c801da70cd4a8088a0dbcd15c0e1fd: Scheduling FlushDeltaMemStoresOp(7c84d5de902a42d0b36e1dc3e98098fb): perf score=3.181125
I20260812 06:16:52.094874  7669 maintenance_manager.cc:643] P d2c801da70cd4a8088a0dbcd15c0e1fd: FlushDeltaMemStoresOp(7c84d5de902a42d0b36e1dc3e98098fb) complete. Timing: real 0.020s	user 0.009s	sys 0.008s Metrics: {"bytes_written":4512902,"delete_count":0,"lbm_write_time_us":7354,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:16:52.095331  7740 maintenance_manager.cc:419] P d2c801da70cd4a8088a0dbcd15c0e1fd: Scheduling UndoDeltaBlockGCOp(7c84d5de902a42d0b36e1dc3e98098fb): 473 bytes on disk
I20260812 06:16:52.095728  7669 maintenance_manager.cc:643] P d2c801da70cd4a8088a0dbcd15c0e1fd: UndoDeltaBlockGCOp(7c84d5de902a42d0b36e1dc3e98098fb) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4}
I20260812 06:16:52.096248  7740 maintenance_manager.cc:419] P d2c801da70cd4a8088a0dbcd15c0e1fd: Scheduling FlushDeltaMemStoresOp(7c84d5de902a42d0b36e1dc3e98098fb): perf score=2.188937
I20260812 06:16:52.105983  7669 maintenance_manager.cc:643] P d2c801da70cd4a8088a0dbcd15c0e1fd: FlushDeltaMemStoresOp(7c84d5de902a42d0b36e1dc3e98098fb) complete. Timing: real 0.010s	user 0.002s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3777,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:52.106415  7740 maintenance_manager.cc:419] P d2c801da70cd4a8088a0dbcd15c0e1fd: Scheduling MajorDeltaCompactionOp(7c84d5de902a42d0b36e1dc3e98098fb): perf score=1.000000
I20260812 06:16:52.286056  7669 maintenance_manager.cc:643] P d2c801da70cd4a8088a0dbcd15c0e1fd: MajorDeltaCompactionOp(7c84d5de902a42d0b36e1dc3e98098fb) complete. Timing: real 0.179s	user 0.139s	sys 0.037s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877328,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":785,"lbm_read_time_us":13960,"lbm_reads_lt_1ms":674,"lbm_write_time_us":35454,"lbm_writes_lt_1ms":643,"mutex_wait_us":80,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":6144,"thread_start_us":83,"threads_started":1,"update_count":3000}
I20260812 06:16:52.286860  7740 maintenance_manager.cc:419] P d2c801da70cd4a8088a0dbcd15c0e1fd: Scheduling FlushDeltaMemStoresOp(7c84d5de902a42d0b36e1dc3e98098fb): perf score=14.095187
I20260812 06:16:52.339433  7669 maintenance_manager.cc:643] P d2c801da70cd4a8088a0dbcd15c0e1fd: FlushDeltaMemStoresOp(7c84d5de902a42d0b36e1dc3e98098fb) complete. Timing: real 0.052s	user 0.031s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21977,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:52.339978  7740 maintenance_manager.cc:419] P d2c801da70cd4a8088a0dbcd15c0e1fd: Scheduling FlushDeltaMemStoresOp(7c84d5de902a42d0b36e1dc3e98098fb): perf score=2.188937
I20260812 06:16:52.355644  7669 maintenance_manager.cc:643] P d2c801da70cd4a8088a0dbcd15c0e1fd: FlushDeltaMemStoresOp(7c84d5de902a42d0b36e1dc3e98098fb) complete. Timing: real 0.015s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5828,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:52.356381  7740 maintenance_manager.cc:419] P d2c801da70cd4a8088a0dbcd15c0e1fd: Scheduling MajorDeltaCompactionOp(7c84d5de902a42d0b36e1dc3e98098fb): perf score=1.000000
I20260812 06:16:52.426028  7331 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.096s	user 1.849s	sys 0.201s
I20260812 06:16:52.485698  7331 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.059s	user 0.001s	sys 0.000s
I20260812 06:16:52.486246  7331 tablet_server.cc:179] TabletServer@127.7.40.193:0 shutting down...
I20260812 06:16:52.504808  7669 maintenance_manager.cc:643] P d2c801da70cd4a8088a0dbcd15c0e1fd: MajorDeltaCompactionOp(7c84d5de902a42d0b36e1dc3e98098fb) complete. Timing: real 0.148s	user 0.099s	sys 0.047s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":553,"lbm_read_time_us":10347,"lbm_reads_lt_1ms":568,"lbm_write_time_us":29558,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11776,"update_count":2500}
I20260812 06:16:52.506059  7331 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:16:52.506326  7331 tablet_replica.cc:333] T 7c84d5de902a42d0b36e1dc3e98098fb P d2c801da70cd4a8088a0dbcd15c0e1fd: stopping tablet replica
I20260812 06:16:52.506480  7331 raft_consensus.cc:2243] T 7c84d5de902a42d0b36e1dc3e98098fb P d2c801da70cd4a8088a0dbcd15c0e1fd [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:52.506666  7331 raft_consensus.cc:2272] T 7c84d5de902a42d0b36e1dc3e98098fb P d2c801da70cd4a8088a0dbcd15c0e1fd [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:52.522532  7331 tablet_server.cc:196] TabletServer@127.7.40.193:0 shutdown complete.
I20260812 06:16:52.551252  7331 master.cc:562] Master@127.7.40.254:37041 shutting down...
I20260812 06:16:52.554910  7331 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 06b2d476398f4859ac7e6859169ae0ed [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:52.555141  7331 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 06b2d476398f4859ac7e6859169ae0ed [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:52.555248  7331 tablet_replica.cc:333] T 00000000000000000000000000000000 P 06b2d476398f4859ac7e6859169ae0ed: stopping tablet replica
I20260812 06:16:52.568881  7331 master.cc:584] Master@127.7.40.254:37041 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5536 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10971 ms total)

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