[==========] 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:57.217881  9491 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.9.68.254:42953
I20260812 06:16:57.218909  9491 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:57.219499  9491 file_cache.cc:504] Constructed file cache file cache with capacity 419430
I20260812 06:16:57.226071  9491 server_base.cc:1061] running on GCE node
W20260812 06:16:57.226147  9497 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:57.226339  9504 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:57.226368  9499 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:57.226833  9491 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:57.226961  9491 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:57.227030  9491 hybrid_clock.cc:648] HybridClock initialized: now 1786515417227028 us; error 0 us; skew 500 ppm
I20260812 06:16:57.228876  9491 webserver.cc:533] Webserver started at http://127.9.68.254:41581/ using document root <none> and password file <none>
I20260812 06:16:57.229396  9491 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:57.229486  9491 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:57.229734  9491 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:57.231290  9491 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515417207375-9491-0/minicluster-data/master-0-root/instance:
uuid: "2bfda2d0d5244bfcb2b5f984e406f12e"
format_stamp: "Formatted at 2026-08-12 06:16:57 on dist-test-slave-04bb"
I20260812 06:16:57.234593  9491 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.002s	sys 0.003s
I20260812 06:16:57.236565  9511 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:57.237479  9491 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.001s
I20260812 06:16:57.237615  9491 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515417207375-9491-0/minicluster-data/master-0-root
uuid: "2bfda2d0d5244bfcb2b5f984e406f12e"
format_stamp: "Formatted at 2026-08-12 06:16:57 on dist-test-slave-04bb"
I20260812 06:16:57.237715  9491 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515417207375-9491-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515417207375-9491-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515417207375-9491-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:57.250017  9491 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:57.250598  9491 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:57.250772  9491 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:57.257978  9491 rpc_server.cc:307] RPC server started. Bound to: 127.9.68.254:42953
I20260812 06:16:57.257982  9605 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.9.68.254:42953 every 8 connection(s)
I20260812 06:16:57.260038  9606 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:57.265242  9606 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 2bfda2d0d5244bfcb2b5f984e406f12e: Bootstrap starting.
I20260812 06:16:57.267413  9606 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 2bfda2d0d5244bfcb2b5f984e406f12e: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:57.268253  9606 log.cc:826] T 00000000000000000000000000000000 P 2bfda2d0d5244bfcb2b5f984e406f12e: Log is configured to *not* fsync() on all Append() calls
I20260812 06:16:57.269798  9606 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 2bfda2d0d5244bfcb2b5f984e406f12e: No bootstrap required, opened a new log
I20260812 06:16:57.272330  9606 raft_consensus.cc:359] T 00000000000000000000000000000000 P 2bfda2d0d5244bfcb2b5f984e406f12e [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2bfda2d0d5244bfcb2b5f984e406f12e" member_type: VOTER }
I20260812 06:16:57.272477  9606 raft_consensus.cc:385] T 00000000000000000000000000000000 P 2bfda2d0d5244bfcb2b5f984e406f12e [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:57.272629  9606 raft_consensus.cc:740] T 00000000000000000000000000000000 P 2bfda2d0d5244bfcb2b5f984e406f12e [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 2bfda2d0d5244bfcb2b5f984e406f12e, State: Initialized, Role: FOLLOWER
I20260812 06:16:57.273186  9606 consensus_queue.cc:260] T 00000000000000000000000000000000 P 2bfda2d0d5244bfcb2b5f984e406f12e [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: "2bfda2d0d5244bfcb2b5f984e406f12e" member_type: VOTER }
I20260812 06:16:57.273340  9606 raft_consensus.cc:399] T 00000000000000000000000000000000 P 2bfda2d0d5244bfcb2b5f984e406f12e [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:57.273432  9606 raft_consensus.cc:493] T 00000000000000000000000000000000 P 2bfda2d0d5244bfcb2b5f984e406f12e [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:57.273584  9606 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 2bfda2d0d5244bfcb2b5f984e406f12e [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:57.274338  9606 raft_consensus.cc:515] T 00000000000000000000000000000000 P 2bfda2d0d5244bfcb2b5f984e406f12e [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2bfda2d0d5244bfcb2b5f984e406f12e" member_type: VOTER }
I20260812 06:16:57.274756  9606 leader_election.cc:304] T 00000000000000000000000000000000 P 2bfda2d0d5244bfcb2b5f984e406f12e [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: 2bfda2d0d5244bfcb2b5f984e406f12e; no voters: 
I20260812 06:16:57.275044  9606 leader_election.cc:290] T 00000000000000000000000000000000 P 2bfda2d0d5244bfcb2b5f984e406f12e [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:57.275177  9609 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 2bfda2d0d5244bfcb2b5f984e406f12e [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:57.275432  9609 raft_consensus.cc:697] T 00000000000000000000000000000000 P 2bfda2d0d5244bfcb2b5f984e406f12e [term 1 LEADER]: Becoming Leader. State: Replica: 2bfda2d0d5244bfcb2b5f984e406f12e, State: Running, Role: LEADER
I20260812 06:16:57.275856  9609 consensus_queue.cc:237] T 00000000000000000000000000000000 P 2bfda2d0d5244bfcb2b5f984e406f12e [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: "2bfda2d0d5244bfcb2b5f984e406f12e" member_type: VOTER }
I20260812 06:16:57.276029  9606 sys_catalog.cc:565] T 00000000000000000000000000000000 P 2bfda2d0d5244bfcb2b5f984e406f12e [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:16:57.277810  9611 sys_catalog.cc:455] T 00000000000000000000000000000000 P 2bfda2d0d5244bfcb2b5f984e406f12e [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "2bfda2d0d5244bfcb2b5f984e406f12e" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2bfda2d0d5244bfcb2b5f984e406f12e" member_type: VOTER } }
I20260812 06:16:57.277940  9611 sys_catalog.cc:458] T 00000000000000000000000000000000 P 2bfda2d0d5244bfcb2b5f984e406f12e [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:57.277817  9612 sys_catalog.cc:455] T 00000000000000000000000000000000 P 2bfda2d0d5244bfcb2b5f984e406f12e [sys.catalog]: SysCatalogTable state changed. Reason: New leader 2bfda2d0d5244bfcb2b5f984e406f12e. Latest consensus state: current_term: 1 leader_uuid: "2bfda2d0d5244bfcb2b5f984e406f12e" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2bfda2d0d5244bfcb2b5f984e406f12e" member_type: VOTER } }
I20260812 06:16:57.278242  9612 sys_catalog.cc:458] T 00000000000000000000000000000000 P 2bfda2d0d5244bfcb2b5f984e406f12e [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:57.278328  9491 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:16:57.278445  9631 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:16:57.280687  9631 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:16:57.285099  9631 catalog_manager.cc:1383] Generated new cluster ID: 8d0e4517bf8b49a28577c17a111e9d2f
I20260812 06:16:57.285184  9631 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:16:57.299770  9631 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:16:57.300678  9631 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:16:57.312460  9631 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 2bfda2d0d5244bfcb2b5f984e406f12e: Generated new TSK 0
I20260812 06:16:57.313103  9631 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:16:57.343030  9491 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:57.345764  9639 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:57.345884  9643 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:57.346009  9640 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:57.346302  9491 server_base.cc:1061] running on GCE node
I20260812 06:16:57.346473  9491 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:57.346517  9491 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:57.346534  9491 hybrid_clock.cc:648] HybridClock initialized: now 1786515417346534 us; error 0 us; skew 500 ppm
I20260812 06:16:57.347525  9491 webserver.cc:533] Webserver started at http://127.9.68.193:41733/ using document root <none> and password file <none>
I20260812 06:16:57.347714  9491 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:57.347775  9491 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:57.347901  9491 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:57.348307  9491 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515417207375-9491-0/minicluster-data/ts-0-root/instance:
uuid: "ebe50f99c71b44b39d6f5a752fb05739"
format_stamp: "Formatted at 2026-08-12 06:16:57 on dist-test-slave-04bb"
I20260812 06:16:57.349902  9491 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:16:57.350941  9653 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:57.351203  9491 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:16:57.351277  9491 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515417207375-9491-0/minicluster-data/ts-0-root
uuid: "ebe50f99c71b44b39d6f5a752fb05739"
format_stamp: "Formatted at 2026-08-12 06:16:57 on dist-test-slave-04bb"
I20260812 06:16:57.351365  9491 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515417207375-9491-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515417207375-9491-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515417207375-9491-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:57.367444  9491 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:57.368297  9491 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:57.368852  9491 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:16:57.369722  9491 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:16:57.369776  9491 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:57.369858  9491 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:16:57.369900  9491 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:57.376713  9491 rpc_server.cc:307] RPC server started. Bound to: 127.9.68.193:38397
I20260812 06:16:57.376807  9764 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.9.68.193:38397 every 8 connection(s)
I20260812 06:16:57.386480  9765 heartbeater.cc:344] Connected to a master server at 127.9.68.254:42953
I20260812 06:16:57.386722  9765 heartbeater.cc:461] Registering TS with master...
I20260812 06:16:57.387163  9765 heartbeater.cc:507] Master 127.9.68.254:42953 requested a full tablet report, sending...
I20260812 06:16:57.388517  9543 ts_manager.cc:194] Registered new tserver with Master: ebe50f99c71b44b39d6f5a752fb05739 (127.9.68.193:38397)
I20260812 06:16:57.388639  9491 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.011237789s
I20260812 06:16:57.390029  9543 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:58836
I20260812 06:16:57.398321  9543 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:58840:
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:57.412763  9701 tablet_service.cc:1511] Processing CreateTablet for tablet dd20a58864a749cba7f5be43e0f7f3d1 (DEFAULT_TABLE table=heavy-update-compaction-test [id=82c338bab14141899ad8688a4423688d]), partition=
I20260812 06:16:57.413224  9701 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet dd20a58864a749cba7f5be43e0f7f3d1. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:16:57.415365  9788 tablet_bootstrap.cc:492] T dd20a58864a749cba7f5be43e0f7f3d1 P ebe50f99c71b44b39d6f5a752fb05739: Bootstrap starting.
I20260812 06:16:57.416754  9788 tablet_bootstrap.cc:654] T dd20a58864a749cba7f5be43e0f7f3d1 P ebe50f99c71b44b39d6f5a752fb05739: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:57.417966  9788 tablet_bootstrap.cc:492] T dd20a58864a749cba7f5be43e0f7f3d1 P ebe50f99c71b44b39d6f5a752fb05739: No bootstrap required, opened a new log
I20260812 06:16:57.418047  9788 ts_tablet_manager.cc:1403] T dd20a58864a749cba7f5be43e0f7f3d1 P ebe50f99c71b44b39d6f5a752fb05739: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:16:57.418540  9788 raft_consensus.cc:359] T dd20a58864a749cba7f5be43e0f7f3d1 P ebe50f99c71b44b39d6f5a752fb05739 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ebe50f99c71b44b39d6f5a752fb05739" member_type: VOTER last_known_addr { host: "127.9.68.193" port: 38397 } }
I20260812 06:16:57.418637  9788 raft_consensus.cc:385] T dd20a58864a749cba7f5be43e0f7f3d1 P ebe50f99c71b44b39d6f5a752fb05739 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:57.418661  9788 raft_consensus.cc:740] T dd20a58864a749cba7f5be43e0f7f3d1 P ebe50f99c71b44b39d6f5a752fb05739 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: ebe50f99c71b44b39d6f5a752fb05739, State: Initialized, Role: FOLLOWER
I20260812 06:16:57.418823  9788 consensus_queue.cc:260] T dd20a58864a749cba7f5be43e0f7f3d1 P ebe50f99c71b44b39d6f5a752fb05739 [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: "ebe50f99c71b44b39d6f5a752fb05739" member_type: VOTER last_known_addr { host: "127.9.68.193" port: 38397 } }
I20260812 06:16:57.418915  9788 raft_consensus.cc:399] T dd20a58864a749cba7f5be43e0f7f3d1 P ebe50f99c71b44b39d6f5a752fb05739 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:57.418964  9788 raft_consensus.cc:493] T dd20a58864a749cba7f5be43e0f7f3d1 P ebe50f99c71b44b39d6f5a752fb05739 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:57.419023  9788 raft_consensus.cc:3060] T dd20a58864a749cba7f5be43e0f7f3d1 P ebe50f99c71b44b39d6f5a752fb05739 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:57.419972  9788 raft_consensus.cc:515] T dd20a58864a749cba7f5be43e0f7f3d1 P ebe50f99c71b44b39d6f5a752fb05739 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ebe50f99c71b44b39d6f5a752fb05739" member_type: VOTER last_known_addr { host: "127.9.68.193" port: 38397 } }
I20260812 06:16:57.420116  9788 leader_election.cc:304] T dd20a58864a749cba7f5be43e0f7f3d1 P ebe50f99c71b44b39d6f5a752fb05739 [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: ebe50f99c71b44b39d6f5a752fb05739; no voters: 
I20260812 06:16:57.420332  9788 leader_election.cc:290] T dd20a58864a749cba7f5be43e0f7f3d1 P ebe50f99c71b44b39d6f5a752fb05739 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:57.420434  9791 raft_consensus.cc:2804] T dd20a58864a749cba7f5be43e0f7f3d1 P ebe50f99c71b44b39d6f5a752fb05739 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:57.420639  9791 raft_consensus.cc:697] T dd20a58864a749cba7f5be43e0f7f3d1 P ebe50f99c71b44b39d6f5a752fb05739 [term 1 LEADER]: Becoming Leader. State: Replica: ebe50f99c71b44b39d6f5a752fb05739, State: Running, Role: LEADER
I20260812 06:16:57.420758  9788 ts_tablet_manager.cc:1434] T dd20a58864a749cba7f5be43e0f7f3d1 P ebe50f99c71b44b39d6f5a752fb05739: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:16:57.420851  9791 consensus_queue.cc:237] T dd20a58864a749cba7f5be43e0f7f3d1 P ebe50f99c71b44b39d6f5a752fb05739 [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: "ebe50f99c71b44b39d6f5a752fb05739" member_type: VOTER last_known_addr { host: "127.9.68.193" port: 38397 } }
I20260812 06:16:57.421037  9765 heartbeater.cc:499] Master 127.9.68.254:42953 was elected leader, sending a full tablet report...
I20260812 06:16:57.423754  9543 catalog_manager.cc:5719] T dd20a58864a749cba7f5be43e0f7f3d1 P ebe50f99c71b44b39d6f5a752fb05739 reported cstate change: term changed from 0 to 1, leader changed from <none> to ebe50f99c71b44b39d6f5a752fb05739 (127.9.68.193). New cstate: current_term: 1 leader_uuid: "ebe50f99c71b44b39d6f5a752fb05739" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ebe50f99c71b44b39d6f5a752fb05739" member_type: VOTER last_known_addr { host: "127.9.68.193" port: 38397 } health_report { overall_health: HEALTHY } } }
I20260812 06:16:57.487381  9491 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.055s	user 0.022s	sys 0.003s
I20260812 06:16:57.627908  9766 maintenance_manager.cc:419] P ebe50f99c71b44b39d6f5a752fb05739: Scheduling FlushMRSOp(dd20a58864a749cba7f5be43e0f7f3d1): perf score=19.054940
I20260812 06:16:57.820595  9660 maintenance_manager.cc:643] P ebe50f99c71b44b39d6f5a752fb05739: FlushMRSOp(dd20a58864a749cba7f5be43e0f7f3d1) complete. Timing: real 0.192s	user 0.130s	sys 0.059s Metrics: {"bytes_written":12717735,"cfile_init":1,"compiler_manager_pool.queue_time_us":196,"delete_count":0,"dirs.queue_time_us":66,"dirs.run_cpu_time_us":212,"dirs.run_wall_time_us":871,"drs_written":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4,"lbm_write_time_us":49546,"lbm_writes_lt_1ms":767,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":428800,"thread_start_us":132,"threads_started":1,"update_count":1550}
I20260812 06:16:57.821866  9766 maintenance_manager.cc:419] P ebe50f99c71b44b39d6f5a752fb05739: Scheduling LogGCOp(dd20a58864a749cba7f5be43e0f7f3d1): free 20743880 bytes of WAL
I20260812 06:16:57.822186  9660 log_reader.cc:385] T dd20a58864a749cba7f5be43e0f7f3d1: removed 2 log segments from log reader
I20260812 06:16:57.822266  9660 log.cc:1079] T dd20a58864a749cba7f5be43e0f7f3d1 P ebe50f99c71b44b39d6f5a752fb05739: Deleting log segment in path: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515417207375-9491-0/minicluster-data/ts-0-root/wals/dd20a58864a749cba7f5be43e0f7f3d1/wal-000000001 (ops 1-6)
I20260812 06:16:57.822333  9660 log.cc:1079] T dd20a58864a749cba7f5be43e0f7f3d1 P ebe50f99c71b44b39d6f5a752fb05739: Deleting log segment in path: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515417207375-9491-0/minicluster-data/ts-0-root/wals/dd20a58864a749cba7f5be43e0f7f3d1/wal-000000002 (ops 7-11)
I20260812 06:16:57.828437  9660 maintenance_manager.cc:643] P ebe50f99c71b44b39d6f5a752fb05739: LogGCOp(dd20a58864a749cba7f5be43e0f7f3d1) complete. Timing: real 0.006s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:16:57.828859  9766 maintenance_manager.cc:419] P ebe50f99c71b44b39d6f5a752fb05739: Scheduling FlushDeltaMemStoresOp(dd20a58864a749cba7f5be43e0f7f3d1): perf score=2.188937
I20260812 06:16:57.850773  9660 maintenance_manager.cc:643] P ebe50f99c71b44b39d6f5a752fb05739: FlushDeltaMemStoresOp(dd20a58864a749cba7f5be43e0f7f3d1) complete. Timing: real 0.022s	user 0.008s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5441,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:57.851253  9766 maintenance_manager.cc:419] P ebe50f99c71b44b39d6f5a752fb05739: Scheduling FlushDeltaMemStoresOp(dd20a58864a749cba7f5be43e0f7f3d1): perf score=2.188937
I20260812 06:16:57.864485  9660 maintenance_manager.cc:643] P ebe50f99c71b44b39d6f5a752fb05739: FlushDeltaMemStoresOp(dd20a58864a749cba7f5be43e0f7f3d1) complete. Timing: real 0.013s	user 0.000s	sys 0.011s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5147,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:57.865082  9766 maintenance_manager.cc:419] P ebe50f99c71b44b39d6f5a752fb05739: Scheduling UndoDeltaBlockGCOp(dd20a58864a749cba7f5be43e0f7f3d1): 16411393 bytes on disk
I20260812 06:16:57.865710  9660 maintenance_manager.cc:643] P ebe50f99c71b44b39d6f5a752fb05739: UndoDeltaBlockGCOp(dd20a58864a749cba7f5be43e0f7f3d1) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":81,"lbm_reads_lt_1ms":4}
I20260812 06:16:57.866142  9766 maintenance_manager.cc:419] P ebe50f99c71b44b39d6f5a752fb05739: Scheduling MajorDeltaCompactionOp(dd20a58864a749cba7f5be43e0f7f3d1): perf score=1.000000
I20260812 06:16:58.045362  9660 maintenance_manager.cc:643] P ebe50f99c71b44b39d6f5a752fb05739: MajorDeltaCompactionOp(dd20a58864a749cba7f5be43e0f7f3d1) complete. Timing: real 0.179s	user 0.118s	sys 0.061s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774799,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":57,"lbm_read_time_us":14136,"lbm_reads_lt_1ms":569,"lbm_write_time_us":29351,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":239,"threads_started":5,"update_count":2500}
I20260812 06:16:58.045838  9766 maintenance_manager.cc:419] P ebe50f99c71b44b39d6f5a752fb05739: Scheduling FlushDeltaMemStoresOp(dd20a58864a749cba7f5be43e0f7f3d1): perf score=10.126437
I20260812 06:16:58.095530  9660 maintenance_manager.cc:643] P ebe50f99c71b44b39d6f5a752fb05739: FlushDeltaMemStoresOp(dd20a58864a749cba7f5be43e0f7f3d1) complete. Timing: real 0.049s	user 0.022s	sys 0.020s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":18496,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:58.096132  9766 maintenance_manager.cc:419] P ebe50f99c71b44b39d6f5a752fb05739: Scheduling FlushDeltaMemStoresOp(dd20a58864a749cba7f5be43e0f7f3d1): perf score=2.188937
I20260812 06:16:58.109618  9660 maintenance_manager.cc:643] P ebe50f99c71b44b39d6f5a752fb05739: FlushDeltaMemStoresOp(dd20a58864a749cba7f5be43e0f7f3d1) complete. Timing: real 0.013s	user 0.008s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5372,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:58.110253  9766 maintenance_manager.cc:419] P ebe50f99c71b44b39d6f5a752fb05739: Scheduling MajorDeltaCompactionOp(dd20a58864a749cba7f5be43e0f7f3d1): perf score=1.000000
I20260812 06:16:58.239055  9660 maintenance_manager.cc:643] P ebe50f99c71b44b39d6f5a752fb05739: MajorDeltaCompactionOp(dd20a58864a749cba7f5be43e0f7f3d1) complete. Timing: real 0.129s	user 0.096s	sys 0.030s 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":125,"lbm_read_time_us":9728,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25303,"lbm_writes_lt_1ms":443,"mutex_wait_us":23,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":15616,"update_count":2000}
I20260812 06:16:58.239651  9766 maintenance_manager.cc:419] P ebe50f99c71b44b39d6f5a752fb05739: Scheduling FlushDeltaMemStoresOp(dd20a58864a749cba7f5be43e0f7f3d1): perf score=10.126437
I20260812 06:16:58.290169  9660 maintenance_manager.cc:643] P ebe50f99c71b44b39d6f5a752fb05739: FlushDeltaMemStoresOp(dd20a58864a749cba7f5be43e0f7f3d1) complete. Timing: real 0.050s	user 0.028s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":22217,"lbm_writes_lt_1ms":303,"mutex_wait_us":19,"reinsert_count":0,"update_count":1500}
I20260812 06:16:58.290633  9766 maintenance_manager.cc:419] P ebe50f99c71b44b39d6f5a752fb05739: Scheduling FlushDeltaMemStoresOp(dd20a58864a749cba7f5be43e0f7f3d1): perf score=2.188937
I20260812 06:16:58.301533  9660 maintenance_manager.cc:643] P ebe50f99c71b44b39d6f5a752fb05739: FlushDeltaMemStoresOp(dd20a58864a749cba7f5be43e0f7f3d1) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4255,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:58.302210  9766 maintenance_manager.cc:419] P ebe50f99c71b44b39d6f5a752fb05739: Scheduling MajorDeltaCompactionOp(dd20a58864a749cba7f5be43e0f7f3d1): perf score=1.000000
I20260812 06:16:58.438555  9660 maintenance_manager.cc:643] P ebe50f99c71b44b39d6f5a752fb05739: MajorDeltaCompactionOp(dd20a58864a749cba7f5be43e0f7f3d1) complete. Timing: real 0.136s	user 0.096s	sys 0.040s 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":544,"lbm_read_time_us":9723,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28489,"lbm_writes_lt_1ms":443,"mutex_wait_us":21,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8832,"update_count":2000}
I20260812 06:16:58.439124  9766 maintenance_manager.cc:419] P ebe50f99c71b44b39d6f5a752fb05739: Scheduling FlushDeltaMemStoresOp(dd20a58864a749cba7f5be43e0f7f3d1): perf score=10.126437
I20260812 06:16:58.477416  9660 maintenance_manager.cc:643] P ebe50f99c71b44b39d6f5a752fb05739: FlushDeltaMemStoresOp(dd20a58864a749cba7f5be43e0f7f3d1) complete. Timing: real 0.038s	user 0.024s	sys 0.008s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":13900,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:58.478008  9766 maintenance_manager.cc:419] P ebe50f99c71b44b39d6f5a752fb05739: Scheduling FlushDeltaMemStoresOp(dd20a58864a749cba7f5be43e0f7f3d1): perf score=2.188937
I20260812 06:16:58.491643  9660 maintenance_manager.cc:643] P ebe50f99c71b44b39d6f5a752fb05739: FlushDeltaMemStoresOp(dd20a58864a749cba7f5be43e0f7f3d1) complete. Timing: real 0.013s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4889,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:58.492110  9766 maintenance_manager.cc:419] P ebe50f99c71b44b39d6f5a752fb05739: Scheduling MajorDeltaCompactionOp(dd20a58864a749cba7f5be43e0f7f3d1): perf score=1.000000
I20260812 06:16:58.617408  9660 maintenance_manager.cc:643] P ebe50f99c71b44b39d6f5a752fb05739: MajorDeltaCompactionOp(dd20a58864a749cba7f5be43e0f7f3d1) complete. Timing: real 0.125s	user 0.089s	sys 0.035s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":153,"lbm_read_time_us":9061,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25718,"lbm_writes_lt_1ms":443,"mutex_wait_us":21,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11008,"update_count":2000}
I20260812 06:16:58.618068  9766 maintenance_manager.cc:419] P ebe50f99c71b44b39d6f5a752fb05739: Scheduling FlushDeltaMemStoresOp(dd20a58864a749cba7f5be43e0f7f3d1): perf score=10.126437
I20260812 06:16:58.670778  9660 maintenance_manager.cc:643] P ebe50f99c71b44b39d6f5a752fb05739: FlushDeltaMemStoresOp(dd20a58864a749cba7f5be43e0f7f3d1) complete. Timing: real 0.052s	user 0.019s	sys 0.031s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":20648,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:16:58.671353  9766 maintenance_manager.cc:419] P ebe50f99c71b44b39d6f5a752fb05739: Scheduling FlushDeltaMemStoresOp(dd20a58864a749cba7f5be43e0f7f3d1): perf score=2.188937
I20260812 06:16:58.682240  9660 maintenance_manager.cc:643] P ebe50f99c71b44b39d6f5a752fb05739: FlushDeltaMemStoresOp(dd20a58864a749cba7f5be43e0f7f3d1) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4356,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:58.682804  9766 maintenance_manager.cc:419] P ebe50f99c71b44b39d6f5a752fb05739: Scheduling MajorDeltaCompactionOp(dd20a58864a749cba7f5be43e0f7f3d1): perf score=1.000000
I20260812 06:16:58.833516  9660 maintenance_manager.cc:643] P ebe50f99c71b44b39d6f5a752fb05739: MajorDeltaCompactionOp(dd20a58864a749cba7f5be43e0f7f3d1) complete. Timing: real 0.150s	user 0.115s	sys 0.035s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":601,"lbm_read_time_us":11718,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27386,"lbm_writes_lt_1ms":443,"mutex_wait_us":302,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:16:58.834183  9766 maintenance_manager.cc:419] P ebe50f99c71b44b39d6f5a752fb05739: Scheduling FlushDeltaMemStoresOp(dd20a58864a749cba7f5be43e0f7f3d1): perf score=10.126437
I20260812 06:16:58.877916  9660 maintenance_manager.cc:643] P ebe50f99c71b44b39d6f5a752fb05739: FlushDeltaMemStoresOp(dd20a58864a749cba7f5be43e0f7f3d1) complete. Timing: real 0.044s	user 0.022s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15552,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:58.878489  9766 maintenance_manager.cc:419] P ebe50f99c71b44b39d6f5a752fb05739: Scheduling FlushDeltaMemStoresOp(dd20a58864a749cba7f5be43e0f7f3d1): perf score=2.188937
I20260812 06:16:58.894817  9660 maintenance_manager.cc:643] P ebe50f99c71b44b39d6f5a752fb05739: FlushDeltaMemStoresOp(dd20a58864a749cba7f5be43e0f7f3d1) complete. Timing: real 0.016s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6541,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:58.895628  9766 maintenance_manager.cc:419] P ebe50f99c71b44b39d6f5a752fb05739: Scheduling MajorDeltaCompactionOp(dd20a58864a749cba7f5be43e0f7f3d1): perf score=1.000000
I20260812 06:16:59.027408  9660 maintenance_manager.cc:643] P ebe50f99c71b44b39d6f5a752fb05739: MajorDeltaCompactionOp(dd20a58864a749cba7f5be43e0f7f3d1) complete. Timing: real 0.132s	user 0.095s	sys 0.036s 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":397,"lbm_read_time_us":10049,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25385,"lbm_writes_lt_1ms":443,"mutex_wait_us":40,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":63488,"update_count":2000}
I20260812 06:16:59.028141  9766 maintenance_manager.cc:419] P ebe50f99c71b44b39d6f5a752fb05739: Scheduling FlushDeltaMemStoresOp(dd20a58864a749cba7f5be43e0f7f3d1): perf score=10.126437
I20260812 06:16:59.067057  9660 maintenance_manager.cc:643] P ebe50f99c71b44b39d6f5a752fb05739: FlushDeltaMemStoresOp(dd20a58864a749cba7f5be43e0f7f3d1) complete. Timing: real 0.039s	user 0.023s	sys 0.013s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":18623,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:16:59.067553  9766 maintenance_manager.cc:419] P ebe50f99c71b44b39d6f5a752fb05739: Scheduling FlushDeltaMemStoresOp(dd20a58864a749cba7f5be43e0f7f3d1): perf score=2.188937
I20260812 06:16:59.078629  9660 maintenance_manager.cc:643] P ebe50f99c71b44b39d6f5a752fb05739: FlushDeltaMemStoresOp(dd20a58864a749cba7f5be43e0f7f3d1) complete. Timing: real 0.011s	user 0.005s	sys 0.004s 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:59.079079  9766 maintenance_manager.cc:419] P ebe50f99c71b44b39d6f5a752fb05739: Scheduling FlushMRSOp(dd20a58864a749cba7f5be43e0f7f3d1): perf score=1.000000
I20260812 06:16:59.109037  9660 maintenance_manager.cc:643] P ebe50f99c71b44b39d6f5a752fb05739: FlushMRSOp(dd20a58864a749cba7f5be43e0f7f3d1) complete. Timing: real 0.030s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":51,"dirs.run_cpu_time_us":203,"dirs.run_wall_time_us":1281,"drs_written":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1991,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:16:59.109860  9766 maintenance_manager.cc:419] P ebe50f99c71b44b39d6f5a752fb05739: Scheduling LogGCOp(dd20a58864a749cba7f5be43e0f7f3d1): free 120553374 bytes of WAL
I20260812 06:16:59.110128  9660 log_reader.cc:385] T dd20a58864a749cba7f5be43e0f7f3d1: removed 12 log segments from log reader
I20260812 06:16:59.110193  9660 log.cc:1079] T dd20a58864a749cba7f5be43e0f7f3d1 P ebe50f99c71b44b39d6f5a752fb05739: Deleting log segment in path: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515417207375-9491-0/minicluster-data/ts-0-root/wals/dd20a58864a749cba7f5be43e0f7f3d1/wal-000000003 (ops 12-16)
I20260812 06:16:59.110232  9660 log.cc:1079] T dd20a58864a749cba7f5be43e0f7f3d1 P ebe50f99c71b44b39d6f5a752fb05739: Deleting log segment in path: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515417207375-9491-0/minicluster-data/ts-0-root/wals/dd20a58864a749cba7f5be43e0f7f3d1/wal-000000004 (ops 17-21)
I20260812 06:16:59.110267  9660 log.cc:1079] T dd20a58864a749cba7f5be43e0f7f3d1 P ebe50f99c71b44b39d6f5a752fb05739: Deleting log segment in path: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515417207375-9491-0/minicluster-data/ts-0-root/wals/dd20a58864a749cba7f5be43e0f7f3d1/wal-000000005 (ops 22-26)
I20260812 06:16:59.110297  9660 log.cc:1079] T dd20a58864a749cba7f5be43e0f7f3d1 P ebe50f99c71b44b39d6f5a752fb05739: Deleting log segment in path: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515417207375-9491-0/minicluster-data/ts-0-root/wals/dd20a58864a749cba7f5be43e0f7f3d1/wal-000000006 (ops 27-30)
I20260812 06:16:59.110327  9660 log.cc:1079] T dd20a58864a749cba7f5be43e0f7f3d1 P ebe50f99c71b44b39d6f5a752fb05739: Deleting log segment in path: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515417207375-9491-0/minicluster-data/ts-0-root/wals/dd20a58864a749cba7f5be43e0f7f3d1/wal-000000007 (ops 31-35)
I20260812 06:16:59.110361  9660 log.cc:1079] T dd20a58864a749cba7f5be43e0f7f3d1 P ebe50f99c71b44b39d6f5a752fb05739: Deleting log segment in path: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515417207375-9491-0/minicluster-data/ts-0-root/wals/dd20a58864a749cba7f5be43e0f7f3d1/wal-000000008 (ops 36-40)
I20260812 06:16:59.110388  9660 log.cc:1079] T dd20a58864a749cba7f5be43e0f7f3d1 P ebe50f99c71b44b39d6f5a752fb05739: Deleting log segment in path: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515417207375-9491-0/minicluster-data/ts-0-root/wals/dd20a58864a749cba7f5be43e0f7f3d1/wal-000000009 (ops 41-45)
I20260812 06:16:59.110421  9660 log.cc:1079] T dd20a58864a749cba7f5be43e0f7f3d1 P ebe50f99c71b44b39d6f5a752fb05739: Deleting log segment in path: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515417207375-9491-0/minicluster-data/ts-0-root/wals/dd20a58864a749cba7f5be43e0f7f3d1/wal-000000010 (ops 46-50)
I20260812 06:16:59.110450  9660 log.cc:1079] T dd20a58864a749cba7f5be43e0f7f3d1 P ebe50f99c71b44b39d6f5a752fb05739: Deleting log segment in path: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515417207375-9491-0/minicluster-data/ts-0-root/wals/dd20a58864a749cba7f5be43e0f7f3d1/wal-000000011 (ops 51-55)
I20260812 06:16:59.110478  9660 log.cc:1079] T dd20a58864a749cba7f5be43e0f7f3d1 P ebe50f99c71b44b39d6f5a752fb05739: Deleting log segment in path: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515417207375-9491-0/minicluster-data/ts-0-root/wals/dd20a58864a749cba7f5be43e0f7f3d1/wal-000000012 (ops 56-60)
I20260812 06:16:59.110507  9660 log.cc:1079] T dd20a58864a749cba7f5be43e0f7f3d1 P ebe50f99c71b44b39d6f5a752fb05739: Deleting log segment in path: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515417207375-9491-0/minicluster-data/ts-0-root/wals/dd20a58864a749cba7f5be43e0f7f3d1/wal-000000013 (ops 61-64)
I20260812 06:16:59.110541  9660 log.cc:1079] T dd20a58864a749cba7f5be43e0f7f3d1 P ebe50f99c71b44b39d6f5a752fb05739: Deleting log segment in path: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515417207375-9491-0/minicluster-data/ts-0-root/wals/dd20a58864a749cba7f5be43e0f7f3d1/wal-000000014 (ops 65-69)
I20260812 06:16:59.142771  9660 maintenance_manager.cc:643] P ebe50f99c71b44b39d6f5a752fb05739: LogGCOp(dd20a58864a749cba7f5be43e0f7f3d1) complete. Timing: real 0.033s	user 0.000s	sys 0.030s Metrics: {}
I20260812 06:16:59.143316  9766 maintenance_manager.cc:419] P ebe50f99c71b44b39d6f5a752fb05739: Scheduling UndoDeltaBlockGCOp(dd20a58864a749cba7f5be43e0f7f3d1): 462 bytes on disk
I20260812 06:16:59.143857  9660 maintenance_manager.cc:643] P ebe50f99c71b44b39d6f5a752fb05739: UndoDeltaBlockGCOp(dd20a58864a749cba7f5be43e0f7f3d1) 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:59.144330  9766 maintenance_manager.cc:419] P ebe50f99c71b44b39d6f5a752fb05739: Scheduling FlushDeltaMemStoresOp(dd20a58864a749cba7f5be43e0f7f3d1): perf score=2.188937
I20260812 06:16:59.158123  9660 maintenance_manager.cc:643] P ebe50f99c71b44b39d6f5a752fb05739: FlushDeltaMemStoresOp(dd20a58864a749cba7f5be43e0f7f3d1) complete. Timing: real 0.014s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4225734,"delete_count":0,"lbm_write_time_us":4421,"lbm_writes_lt_1ms":106,"mutex_wait_us":53,"reinsert_count":0,"update_count":515}
I20260812 06:16:59.158478  9766 maintenance_manager.cc:419] P ebe50f99c71b44b39d6f5a752fb05739: Scheduling FlushDeltaMemStoresOp(dd20a58864a749cba7f5be43e0f7f3d1): perf score=2.188937
I20260812 06:16:59.168293  9660 maintenance_manager.cc:643] P ebe50f99c71b44b39d6f5a752fb05739: FlushDeltaMemStoresOp(dd20a58864a749cba7f5be43e0f7f3d1) complete. Timing: real 0.010s	user 0.005s	sys 0.003s Metrics: {"bytes_written":3979583,"delete_count":0,"lbm_write_time_us":3964,"lbm_writes_lt_1ms":100,"reinsert_count":0,"update_count":485}
I20260812 06:16:59.168684  9766 maintenance_manager.cc:419] P ebe50f99c71b44b39d6f5a752fb05739: Scheduling MajorDeltaCompactionOp(dd20a58864a749cba7f5be43e0f7f3d1): perf score=1.000000
I20260812 06:16:59.351269  9660 maintenance_manager.cc:643] P ebe50f99c71b44b39d6f5a752fb05739: MajorDeltaCompactionOp(dd20a58864a749cba7f5be43e0f7f3d1) complete. Timing: real 0.182s	user 0.143s	sys 0.033s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877339,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":374,"lbm_read_time_us":11962,"lbm_reads_lt_1ms":674,"lbm_write_time_us":39563,"lbm_writes_lt_1ms":643,"mutex_wait_us":48,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2688,"thread_start_us":101,"threads_started":1,"update_count":3000}
I20260812 06:16:59.351933  9766 maintenance_manager.cc:419] P ebe50f99c71b44b39d6f5a752fb05739: Scheduling FlushDeltaMemStoresOp(dd20a58864a749cba7f5be43e0f7f3d1): perf score=14.095187
I20260812 06:16:59.407655  9660 maintenance_manager.cc:643] P ebe50f99c71b44b39d6f5a752fb05739: FlushDeltaMemStoresOp(dd20a58864a749cba7f5be43e0f7f3d1) complete. Timing: real 0.056s	user 0.040s	sys 0.013s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23625,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:59.408149  9766 maintenance_manager.cc:419] P ebe50f99c71b44b39d6f5a752fb05739: Scheduling FlushDeltaMemStoresOp(dd20a58864a749cba7f5be43e0f7f3d1): perf score=2.188937
I20260812 06:16:59.431275  9660 maintenance_manager.cc:643] P ebe50f99c71b44b39d6f5a752fb05739: FlushDeltaMemStoresOp(dd20a58864a749cba7f5be43e0f7f3d1) complete. Timing: real 0.023s	user 0.012s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6908,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:59.431797  9766 maintenance_manager.cc:419] P ebe50f99c71b44b39d6f5a752fb05739: Scheduling MajorDeltaCompactionOp(dd20a58864a749cba7f5be43e0f7f3d1): perf score=1.000000
I20260812 06:16:59.593111  9660 maintenance_manager.cc:643] P ebe50f99c71b44b39d6f5a752fb05739: MajorDeltaCompactionOp(dd20a58864a749cba7f5be43e0f7f3d1) complete. Timing: real 0.161s	user 0.124s	sys 0.028s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":243,"lbm_read_time_us":10772,"lbm_reads_lt_1ms":564,"lbm_write_time_us":33464,"lbm_writes_lt_1ms":543,"mutex_wait_us":46,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:16:59.593765  9766 maintenance_manager.cc:419] P ebe50f99c71b44b39d6f5a752fb05739: Scheduling FlushDeltaMemStoresOp(dd20a58864a749cba7f5be43e0f7f3d1): perf score=14.095187
I20260812 06:16:59.657070  9660 maintenance_manager.cc:643] P ebe50f99c71b44b39d6f5a752fb05739: FlushDeltaMemStoresOp(dd20a58864a749cba7f5be43e0f7f3d1) complete. Timing: real 0.061s	user 0.043s	sys 0.007s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":22411,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:59.657559  9766 maintenance_manager.cc:419] P ebe50f99c71b44b39d6f5a752fb05739: Scheduling FlushDeltaMemStoresOp(dd20a58864a749cba7f5be43e0f7f3d1): perf score=2.188937
I20260812 06:16:59.667862  9660 maintenance_manager.cc:643] P ebe50f99c71b44b39d6f5a752fb05739: FlushDeltaMemStoresOp(dd20a58864a749cba7f5be43e0f7f3d1) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4096,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:59.668612  9766 maintenance_manager.cc:419] P ebe50f99c71b44b39d6f5a752fb05739: Scheduling MajorDeltaCompactionOp(dd20a58864a749cba7f5be43e0f7f3d1): perf score=1.000000
I20260812 06:16:59.857393  9660 maintenance_manager.cc:643] P ebe50f99c71b44b39d6f5a752fb05739: MajorDeltaCompactionOp(dd20a58864a749cba7f5be43e0f7f3d1) complete. Timing: real 0.189s	user 0.100s	sys 0.084s 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":638,"lbm_read_time_us":14380,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33798,"lbm_writes_lt_1ms":543,"mutex_wait_us":37,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:16:59.857889  9766 maintenance_manager.cc:419] P ebe50f99c71b44b39d6f5a752fb05739: Scheduling FlushDeltaMemStoresOp(dd20a58864a749cba7f5be43e0f7f3d1): perf score=14.095187
I20260812 06:16:59.907675  9660 maintenance_manager.cc:643] P ebe50f99c71b44b39d6f5a752fb05739: FlushDeltaMemStoresOp(dd20a58864a749cba7f5be43e0f7f3d1) complete. Timing: real 0.050s	user 0.026s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22633,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:59.908169  9766 maintenance_manager.cc:419] P ebe50f99c71b44b39d6f5a752fb05739: Scheduling MajorDeltaCompactionOp(dd20a58864a749cba7f5be43e0f7f3d1): perf score=1.000000
I20260812 06:17:00.057358  9660 maintenance_manager.cc:643] P ebe50f99c71b44b39d6f5a752fb05739: MajorDeltaCompactionOp(dd20a58864a749cba7f5be43e0f7f3d1) complete. Timing: real 0.149s	user 0.090s	sys 0.048s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672158,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":335,"lbm_read_time_us":9586,"lbm_reads_lt_1ms":467,"lbm_write_time_us":24240,"lbm_writes_lt_1ms":443,"mutex_wait_us":76,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2000}
I20260812 06:17:00.058034  9766 maintenance_manager.cc:419] P ebe50f99c71b44b39d6f5a752fb05739: Scheduling FlushDeltaMemStoresOp(dd20a58864a749cba7f5be43e0f7f3d1): perf score=14.095187
I20260812 06:17:00.110697  9660 maintenance_manager.cc:643] P ebe50f99c71b44b39d6f5a752fb05739: FlushDeltaMemStoresOp(dd20a58864a749cba7f5be43e0f7f3d1) complete. Timing: real 0.052s	user 0.034s	sys 0.008s Metrics: {"bytes_written":16409912,"delete_count":0,"lbm_write_time_us":19976,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:00.111218  9766 maintenance_manager.cc:419] P ebe50f99c71b44b39d6f5a752fb05739: Scheduling FlushDeltaMemStoresOp(dd20a58864a749cba7f5be43e0f7f3d1): perf score=2.188937
I20260812 06:17:00.122959  9660 maintenance_manager.cc:643] P ebe50f99c71b44b39d6f5a752fb05739: FlushDeltaMemStoresOp(dd20a58864a749cba7f5be43e0f7f3d1) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4449,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:00.123406  9766 maintenance_manager.cc:419] P ebe50f99c71b44b39d6f5a752fb05739: Scheduling MajorDeltaCompactionOp(dd20a58864a749cba7f5be43e0f7f3d1): perf score=1.000000
I20260812 06:17:00.313362  9660 maintenance_manager.cc:643] P ebe50f99c71b44b39d6f5a752fb05739: MajorDeltaCompactionOp(dd20a58864a749cba7f5be43e0f7f3d1) complete. Timing: real 0.190s	user 0.120s	sys 0.050s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774699,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":244,"lbm_read_time_us":10335,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30170,"lbm_writes_lt_1ms":543,"mutex_wait_us":53,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:17:00.314006  9766 maintenance_manager.cc:419] P ebe50f99c71b44b39d6f5a752fb05739: Scheduling FlushDeltaMemStoresOp(dd20a58864a749cba7f5be43e0f7f3d1): perf score=14.095187
I20260812 06:17:00.370141  9660 maintenance_manager.cc:643] P ebe50f99c71b44b39d6f5a752fb05739: FlushDeltaMemStoresOp(dd20a58864a749cba7f5be43e0f7f3d1) complete. Timing: real 0.056s	user 0.035s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23129,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:00.370646  9766 maintenance_manager.cc:419] P ebe50f99c71b44b39d6f5a752fb05739: Scheduling FlushDeltaMemStoresOp(dd20a58864a749cba7f5be43e0f7f3d1): perf score=2.188937
I20260812 06:17:00.383004  9660 maintenance_manager.cc:643] P ebe50f99c71b44b39d6f5a752fb05739: FlushDeltaMemStoresOp(dd20a58864a749cba7f5be43e0f7f3d1) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4404,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:00.383603  9766 maintenance_manager.cc:419] P ebe50f99c71b44b39d6f5a752fb05739: Scheduling MajorDeltaCompactionOp(dd20a58864a749cba7f5be43e0f7f3d1): perf score=1.000000
I20260812 06:17:00.550175  9660 maintenance_manager.cc:643] P ebe50f99c71b44b39d6f5a752fb05739: MajorDeltaCompactionOp(dd20a58864a749cba7f5be43e0f7f3d1) complete. Timing: real 0.166s	user 0.123s	sys 0.032s 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":245,"lbm_read_time_us":11010,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30075,"lbm_writes_lt_1ms":543,"mutex_wait_us":79,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7680,"update_count":2500}
I20260812 06:17:00.550861  9766 maintenance_manager.cc:419] P ebe50f99c71b44b39d6f5a752fb05739: Scheduling FlushDeltaMemStoresOp(dd20a58864a749cba7f5be43e0f7f3d1): perf score=14.095187
I20260812 06:17:00.611392  9660 maintenance_manager.cc:643] P ebe50f99c71b44b39d6f5a752fb05739: FlushDeltaMemStoresOp(dd20a58864a749cba7f5be43e0f7f3d1) complete. Timing: real 0.060s	user 0.025s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23789,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:00.611824  9766 maintenance_manager.cc:419] P ebe50f99c71b44b39d6f5a752fb05739: Scheduling FlushDeltaMemStoresOp(dd20a58864a749cba7f5be43e0f7f3d1): perf score=2.188937
I20260812 06:17:00.621986  9660 maintenance_manager.cc:643] P ebe50f99c71b44b39d6f5a752fb05739: FlushDeltaMemStoresOp(dd20a58864a749cba7f5be43e0f7f3d1) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4141,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:00.622437  9766 maintenance_manager.cc:419] P ebe50f99c71b44b39d6f5a752fb05739: Scheduling FlushMRSOp(dd20a58864a749cba7f5be43e0f7f3d1): perf score=1.000000
I20260812 06:17:00.653929  9660 maintenance_manager.cc:643] P ebe50f99c71b44b39d6f5a752fb05739: FlushMRSOp(dd20a58864a749cba7f5be43e0f7f3d1) complete. Timing: real 0.031s	user 0.028s	sys 0.002s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":36,"dirs.run_cpu_time_us":191,"dirs.run_wall_time_us":1331,"drs_written":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1406,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:17:00.654594  9766 maintenance_manager.cc:419] P ebe50f99c71b44b39d6f5a752fb05739: Scheduling LogGCOp(dd20a58864a749cba7f5be43e0f7f3d1): free 121006447 bytes of WAL
I20260812 06:17:00.654816  9660 log_reader.cc:385] T dd20a58864a749cba7f5be43e0f7f3d1: removed 12 log segments from log reader
I20260812 06:17:00.654861  9660 log.cc:1079] T dd20a58864a749cba7f5be43e0f7f3d1 P ebe50f99c71b44b39d6f5a752fb05739: Deleting log segment in path: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515417207375-9491-0/minicluster-data/ts-0-root/wals/dd20a58864a749cba7f5be43e0f7f3d1/wal-000000015 (ops 70-74)
I20260812 06:17:00.654891  9660 log.cc:1079] T dd20a58864a749cba7f5be43e0f7f3d1 P ebe50f99c71b44b39d6f5a752fb05739: Deleting log segment in path: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515417207375-9491-0/minicluster-data/ts-0-root/wals/dd20a58864a749cba7f5be43e0f7f3d1/wal-000000016 (ops 75-79)
I20260812 06:17:00.654953  9660 log.cc:1079] T dd20a58864a749cba7f5be43e0f7f3d1 P ebe50f99c71b44b39d6f5a752fb05739: Deleting log segment in path: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515417207375-9491-0/minicluster-data/ts-0-root/wals/dd20a58864a749cba7f5be43e0f7f3d1/wal-000000017 (ops 80-84)
I20260812 06:17:00.654983  9660 log.cc:1079] T dd20a58864a749cba7f5be43e0f7f3d1 P ebe50f99c71b44b39d6f5a752fb05739: Deleting log segment in path: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515417207375-9491-0/minicluster-data/ts-0-root/wals/dd20a58864a749cba7f5be43e0f7f3d1/wal-000000018 (ops 85-89)
I20260812 06:17:00.655020  9660 log.cc:1079] T dd20a58864a749cba7f5be43e0f7f3d1 P ebe50f99c71b44b39d6f5a752fb05739: Deleting log segment in path: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515417207375-9491-0/minicluster-data/ts-0-root/wals/dd20a58864a749cba7f5be43e0f7f3d1/wal-000000019 (ops 90-94)
I20260812 06:17:00.655046  9660 log.cc:1079] T dd20a58864a749cba7f5be43e0f7f3d1 P ebe50f99c71b44b39d6f5a752fb05739: Deleting log segment in path: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515417207375-9491-0/minicluster-data/ts-0-root/wals/dd20a58864a749cba7f5be43e0f7f3d1/wal-000000020 (ops 95-99)
I20260812 06:17:00.655086  9660 log.cc:1079] T dd20a58864a749cba7f5be43e0f7f3d1 P ebe50f99c71b44b39d6f5a752fb05739: Deleting log segment in path: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515417207375-9491-0/minicluster-data/ts-0-root/wals/dd20a58864a749cba7f5be43e0f7f3d1/wal-000000021 (ops 100-104)
I20260812 06:17:00.655125  9660 log.cc:1079] T dd20a58864a749cba7f5be43e0f7f3d1 P ebe50f99c71b44b39d6f5a752fb05739: Deleting log segment in path: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515417207375-9491-0/minicluster-data/ts-0-root/wals/dd20a58864a749cba7f5be43e0f7f3d1/wal-000000022 (ops 105-108)
I20260812 06:17:00.655164  9660 log.cc:1079] T dd20a58864a749cba7f5be43e0f7f3d1 P ebe50f99c71b44b39d6f5a752fb05739: Deleting log segment in path: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515417207375-9491-0/minicluster-data/ts-0-root/wals/dd20a58864a749cba7f5be43e0f7f3d1/wal-000000023 (ops 109-113)
I20260812 06:17:00.655202  9660 log.cc:1079] T dd20a58864a749cba7f5be43e0f7f3d1 P ebe50f99c71b44b39d6f5a752fb05739: Deleting log segment in path: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515417207375-9491-0/minicluster-data/ts-0-root/wals/dd20a58864a749cba7f5be43e0f7f3d1/wal-000000024 (ops 114-118)
I20260812 06:17:00.655239  9660 log.cc:1079] T dd20a58864a749cba7f5be43e0f7f3d1 P ebe50f99c71b44b39d6f5a752fb05739: Deleting log segment in path: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515417207375-9491-0/minicluster-data/ts-0-root/wals/dd20a58864a749cba7f5be43e0f7f3d1/wal-000000025 (ops 119-123)
I20260812 06:17:00.655277  9660 log.cc:1079] T dd20a58864a749cba7f5be43e0f7f3d1 P ebe50f99c71b44b39d6f5a752fb05739: Deleting log segment in path: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515417207375-9491-0/minicluster-data/ts-0-root/wals/dd20a58864a749cba7f5be43e0f7f3d1/wal-000000026 (ops 124-128)
I20260812 06:17:00.683619  9660 maintenance_manager.cc:643] P ebe50f99c71b44b39d6f5a752fb05739: LogGCOp(dd20a58864a749cba7f5be43e0f7f3d1) complete. Timing: real 0.029s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:17:00.684063  9766 maintenance_manager.cc:419] P ebe50f99c71b44b39d6f5a752fb05739: Scheduling UndoDeltaBlockGCOp(dd20a58864a749cba7f5be43e0f7f3d1): 482 bytes on disk
I20260812 06:17:00.684788  9660 maintenance_manager.cc:643] P ebe50f99c71b44b39d6f5a752fb05739: UndoDeltaBlockGCOp(dd20a58864a749cba7f5be43e0f7f3d1) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4}
I20260812 06:17:00.685343  9766 maintenance_manager.cc:419] P ebe50f99c71b44b39d6f5a752fb05739: Scheduling FlushDeltaMemStoresOp(dd20a58864a749cba7f5be43e0f7f3d1): perf score=4.173312
I20260812 06:17:00.710261  9660 maintenance_manager.cc:643] P ebe50f99c71b44b39d6f5a752fb05739: FlushDeltaMemStoresOp(dd20a58864a749cba7f5be43e0f7f3d1) complete. Timing: real 0.025s	user 0.008s	sys 0.014s Metrics: {"bytes_written":5620561,"delete_count":0,"lbm_write_time_us":6121,"lbm_writes_lt_1ms":140,"reinsert_count":0,"update_count":685}
I20260812 06:17:00.710736  9766 maintenance_manager.cc:419] P ebe50f99c71b44b39d6f5a752fb05739: Scheduling LogGCOp(dd20a58864a749cba7f5be43e0f7f3d1): free 11564891 bytes of WAL
I20260812 06:17:00.710958  9660 log_reader.cc:385] T dd20a58864a749cba7f5be43e0f7f3d1: removed 1 log segments from log reader
I20260812 06:17:00.711004  9660 log.cc:1079] T dd20a58864a749cba7f5be43e0f7f3d1 P ebe50f99c71b44b39d6f5a752fb05739: Deleting log segment in path: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515417207375-9491-0/minicluster-data/ts-0-root/wals/dd20a58864a749cba7f5be43e0f7f3d1/wal-000000027 (ops 129-132)
I20260812 06:17:00.713578  9660 maintenance_manager.cc:643] P ebe50f99c71b44b39d6f5a752fb05739: LogGCOp(dd20a58864a749cba7f5be43e0f7f3d1) complete. Timing: real 0.003s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:17:00.713896  9766 maintenance_manager.cc:419] P ebe50f99c71b44b39d6f5a752fb05739: Scheduling FlushDeltaMemStoresOp(dd20a58864a749cba7f5be43e0f7f3d1): perf score=1.196750
I20260812 06:17:00.721908  9660 maintenance_manager.cc:643] P ebe50f99c71b44b39d6f5a752fb05739: FlushDeltaMemStoresOp(dd20a58864a749cba7f5be43e0f7f3d1) complete. Timing: real 0.008s	user 0.005s	sys 0.002s Metrics: {"bytes_written":2584729,"delete_count":0,"lbm_write_time_us":2905,"lbm_writes_lt_1ms":66,"reinsert_count":0,"update_count":315}
I20260812 06:17:00.722312  9766 maintenance_manager.cc:419] P ebe50f99c71b44b39d6f5a752fb05739: Scheduling MajorDeltaCompactionOp(dd20a58864a749cba7f5be43e0f7f3d1): perf score=1.000000
I20260812 06:17:00.965752  9660 maintenance_manager.cc:643] P ebe50f99c71b44b39d6f5a752fb05739: MajorDeltaCompactionOp(dd20a58864a749cba7f5be43e0f7f3d1) complete. Timing: real 0.243s	user 0.147s	sys 0.090s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979715,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":163,"lbm_read_time_us":17075,"lbm_reads_lt_1ms":774,"lbm_write_time_us":45576,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"thread_start_us":75,"threads_started":1,"update_count":3500}
I20260812 06:17:00.966370  9766 maintenance_manager.cc:419] P ebe50f99c71b44b39d6f5a752fb05739: Scheduling FlushDeltaMemStoresOp(dd20a58864a749cba7f5be43e0f7f3d1): perf score=18.063937
I20260812 06:17:01.038714  9660 maintenance_manager.cc:643] P ebe50f99c71b44b39d6f5a752fb05739: FlushDeltaMemStoresOp(dd20a58864a749cba7f5be43e0f7f3d1) complete. Timing: real 0.072s	user 0.058s	sys 0.012s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":34693,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":501,"reinsert_count":0,"update_count":2500}
I20260812 06:17:01.039215  9766 maintenance_manager.cc:419] P ebe50f99c71b44b39d6f5a752fb05739: Scheduling FlushDeltaMemStoresOp(dd20a58864a749cba7f5be43e0f7f3d1): perf score=2.188937
I20260812 06:17:01.049983  9660 maintenance_manager.cc:643] P ebe50f99c71b44b39d6f5a752fb05739: FlushDeltaMemStoresOp(dd20a58864a749cba7f5be43e0f7f3d1) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4132,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:01.050624  9766 maintenance_manager.cc:419] P ebe50f99c71b44b39d6f5a752fb05739: Scheduling MajorDeltaCompactionOp(dd20a58864a749cba7f5be43e0f7f3d1): perf score=1.000000
I20260812 06:17:01.260742  9660 maintenance_manager.cc:643] P ebe50f99c71b44b39d6f5a752fb05739: MajorDeltaCompactionOp(dd20a58864a749cba7f5be43e0f7f3d1) complete. Timing: real 0.210s	user 0.157s	sys 0.052s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877102,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1090,"lbm_read_time_us":15167,"lbm_reads_lt_1ms":672,"lbm_write_time_us":37501,"lbm_writes_lt_1ms":643,"mutex_wait_us":312,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":3000}
I20260812 06:17:01.261354  9766 maintenance_manager.cc:419] P ebe50f99c71b44b39d6f5a752fb05739: Scheduling FlushDeltaMemStoresOp(dd20a58864a749cba7f5be43e0f7f3d1): perf score=14.095187
I20260812 06:17:01.321834  9660 maintenance_manager.cc:643] P ebe50f99c71b44b39d6f5a752fb05739: FlushDeltaMemStoresOp(dd20a58864a749cba7f5be43e0f7f3d1) complete. Timing: real 0.060s	user 0.027s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22314,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:01.322345  9766 maintenance_manager.cc:419] P ebe50f99c71b44b39d6f5a752fb05739: Scheduling FlushDeltaMemStoresOp(dd20a58864a749cba7f5be43e0f7f3d1): perf score=2.188937
I20260812 06:17:01.333647  9660 maintenance_manager.cc:643] P ebe50f99c71b44b39d6f5a752fb05739: FlushDeltaMemStoresOp(dd20a58864a749cba7f5be43e0f7f3d1) complete. Timing: real 0.011s	user 0.004s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4282,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:01.334115  9766 maintenance_manager.cc:419] P ebe50f99c71b44b39d6f5a752fb05739: Scheduling MajorDeltaCompactionOp(dd20a58864a749cba7f5be43e0f7f3d1): perf score=1.000000
I20260812 06:17:01.514477  9660 maintenance_manager.cc:643] P ebe50f99c71b44b39d6f5a752fb05739: MajorDeltaCompactionOp(dd20a58864a749cba7f5be43e0f7f3d1) complete. Timing: real 0.180s	user 0.150s	sys 0.029s 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":815,"lbm_read_time_us":12364,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33038,"lbm_writes_lt_1ms":543,"mutex_wait_us":294,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":119680,"update_count":2500}
I20260812 06:17:01.515161  9766 maintenance_manager.cc:419] P ebe50f99c71b44b39d6f5a752fb05739: Scheduling FlushDeltaMemStoresOp(dd20a58864a749cba7f5be43e0f7f3d1): perf score=14.095187
I20260812 06:17:01.575377  9660 maintenance_manager.cc:643] P ebe50f99c71b44b39d6f5a752fb05739: FlushDeltaMemStoresOp(dd20a58864a749cba7f5be43e0f7f3d1) complete. Timing: real 0.060s	user 0.028s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20580,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:01.575970  9766 maintenance_manager.cc:419] P ebe50f99c71b44b39d6f5a752fb05739: Scheduling FlushDeltaMemStoresOp(dd20a58864a749cba7f5be43e0f7f3d1): perf score=2.188937
I20260812 06:17:01.587373  9660 maintenance_manager.cc:643] P ebe50f99c71b44b39d6f5a752fb05739: FlushDeltaMemStoresOp(dd20a58864a749cba7f5be43e0f7f3d1) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4486,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:01.589000  9766 maintenance_manager.cc:419] P ebe50f99c71b44b39d6f5a752fb05739: Scheduling MajorDeltaCompactionOp(dd20a58864a749cba7f5be43e0f7f3d1): perf score=1.000000
I20260812 06:17:01.779192  9660 maintenance_manager.cc:643] P ebe50f99c71b44b39d6f5a752fb05739: MajorDeltaCompactionOp(dd20a58864a749cba7f5be43e0f7f3d1) complete. Timing: real 0.190s	user 0.130s	sys 0.053s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":285,"lbm_read_time_us":13339,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31585,"lbm_writes_lt_1ms":543,"mutex_wait_us":81,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2500}
I20260812 06:17:01.779954  9766 maintenance_manager.cc:419] P ebe50f99c71b44b39d6f5a752fb05739: Scheduling FlushDeltaMemStoresOp(dd20a58864a749cba7f5be43e0f7f3d1): perf score=14.095187
I20260812 06:17:01.845053  9660 maintenance_manager.cc:643] P ebe50f99c71b44b39d6f5a752fb05739: FlushDeltaMemStoresOp(dd20a58864a749cba7f5be43e0f7f3d1) complete. Timing: real 0.065s	user 0.033s	sys 0.031s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23758,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:01.845677  9766 maintenance_manager.cc:419] P ebe50f99c71b44b39d6f5a752fb05739: Scheduling FlushDeltaMemStoresOp(dd20a58864a749cba7f5be43e0f7f3d1): perf score=2.188937
I20260812 06:17:01.857417  9660 maintenance_manager.cc:643] P ebe50f99c71b44b39d6f5a752fb05739: FlushDeltaMemStoresOp(dd20a58864a749cba7f5be43e0f7f3d1) complete. Timing: real 0.012s	user 0.001s	sys 0.010s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4394,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:01.857916  9766 maintenance_manager.cc:419] P ebe50f99c71b44b39d6f5a752fb05739: Scheduling MajorDeltaCompactionOp(dd20a58864a749cba7f5be43e0f7f3d1): perf score=1.000000
I20260812 06:17:02.042524  9660 maintenance_manager.cc:643] P ebe50f99c71b44b39d6f5a752fb05739: MajorDeltaCompactionOp(dd20a58864a749cba7f5be43e0f7f3d1) complete. Timing: real 0.184s	user 0.128s	sys 0.054s 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":256,"lbm_read_time_us":13809,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31201,"lbm_writes_lt_1ms":543,"mutex_wait_us":2,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9216,"update_count":2500}
I20260812 06:17:02.043243  9766 maintenance_manager.cc:419] P ebe50f99c71b44b39d6f5a752fb05739: Scheduling FlushDeltaMemStoresOp(dd20a58864a749cba7f5be43e0f7f3d1): perf score=10.126437
I20260812 06:17:02.082898  9660 maintenance_manager.cc:643] P ebe50f99c71b44b39d6f5a752fb05739: FlushDeltaMemStoresOp(dd20a58864a749cba7f5be43e0f7f3d1) complete. Timing: real 0.039s	user 0.012s	sys 0.025s Metrics: {"bytes_written":12430563,"delete_count":0,"lbm_write_time_us":17742,"lbm_writes_lt_1ms":306,"mutex_wait_us":159,"reinsert_count":0,"update_count":1515}
I20260812 06:17:02.083456  9766 maintenance_manager.cc:419] P ebe50f99c71b44b39d6f5a752fb05739: Scheduling FlushDeltaMemStoresOp(dd20a58864a749cba7f5be43e0f7f3d1): perf score=2.188937
I20260812 06:17:02.095202  9660 maintenance_manager.cc:643] P ebe50f99c71b44b39d6f5a752fb05739: FlushDeltaMemStoresOp(dd20a58864a749cba7f5be43e0f7f3d1) complete. Timing: real 0.012s	user 0.004s	sys 0.005s Metrics: {"bytes_written":3979584,"delete_count":0,"lbm_write_time_us":4137,"lbm_writes_lt_1ms":100,"reinsert_count":0,"update_count":485}
I20260812 06:17:02.095844  9766 maintenance_manager.cc:419] P ebe50f99c71b44b39d6f5a752fb05739: Scheduling MajorDeltaCompactionOp(dd20a58864a749cba7f5be43e0f7f3d1): perf score=1.000000
I20260812 06:17:02.234809  9660 maintenance_manager.cc:643] P ebe50f99c71b44b39d6f5a752fb05739: MajorDeltaCompactionOp(dd20a58864a749cba7f5be43e0f7f3d1) complete. Timing: real 0.139s	user 0.103s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672275,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":345,"lbm_read_time_us":10729,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24308,"lbm_writes_lt_1ms":443,"mutex_wait_us":109,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6144,"update_count":2000}
I20260812 06:17:02.235561  9766 maintenance_manager.cc:419] P ebe50f99c71b44b39d6f5a752fb05739: Scheduling FlushDeltaMemStoresOp(dd20a58864a749cba7f5be43e0f7f3d1): perf score=10.126437
I20260812 06:17:02.281909  9660 maintenance_manager.cc:643] P ebe50f99c71b44b39d6f5a752fb05739: FlushDeltaMemStoresOp(dd20a58864a749cba7f5be43e0f7f3d1) complete. Timing: real 0.046s	user 0.018s	sys 0.016s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":16291,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:02.282492  9766 maintenance_manager.cc:419] P ebe50f99c71b44b39d6f5a752fb05739: Scheduling FlushDeltaMemStoresOp(dd20a58864a749cba7f5be43e0f7f3d1): perf score=2.188937
I20260812 06:17:02.293819  9660 maintenance_manager.cc:643] P ebe50f99c71b44b39d6f5a752fb05739: FlushDeltaMemStoresOp(dd20a58864a749cba7f5be43e0f7f3d1) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4206,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:02.294565  9766 maintenance_manager.cc:419] P ebe50f99c71b44b39d6f5a752fb05739: Scheduling FlushMRSOp(dd20a58864a749cba7f5be43e0f7f3d1): perf score=1.000000
I20260812 06:17:02.326148  9660 maintenance_manager.cc:643] P ebe50f99c71b44b39d6f5a752fb05739: FlushMRSOp(dd20a58864a749cba7f5be43e0f7f3d1) complete. Timing: real 0.031s	user 0.030s	sys 0.000s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":76,"dirs.run_cpu_time_us":241,"dirs.run_wall_time_us":1255,"drs_written":1,"lbm_read_time_us":45,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1850,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:17:02.326843  9766 maintenance_manager.cc:419] P ebe50f99c71b44b39d6f5a752fb05739: Scheduling LogGCOp(dd20a58864a749cba7f5be43e0f7f3d1): free 120553651 bytes of WAL
I20260812 06:17:02.327083  9660 log_reader.cc:385] T dd20a58864a749cba7f5be43e0f7f3d1: removed 12 log segments from log reader
I20260812 06:17:02.327131  9660 log.cc:1079] T dd20a58864a749cba7f5be43e0f7f3d1 P ebe50f99c71b44b39d6f5a752fb05739: Deleting log segment in path: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515417207375-9491-0/minicluster-data/ts-0-root/wals/dd20a58864a749cba7f5be43e0f7f3d1/wal-000000028 (ops 133-137)
I20260812 06:17:02.327181  9660 log.cc:1079] T dd20a58864a749cba7f5be43e0f7f3d1 P ebe50f99c71b44b39d6f5a752fb05739: Deleting log segment in path: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515417207375-9491-0/minicluster-data/ts-0-root/wals/dd20a58864a749cba7f5be43e0f7f3d1/wal-000000029 (ops 138-142)
I20260812 06:17:02.327227  9660 log.cc:1079] T dd20a58864a749cba7f5be43e0f7f3d1 P ebe50f99c71b44b39d6f5a752fb05739: Deleting log segment in path: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515417207375-9491-0/minicluster-data/ts-0-root/wals/dd20a58864a749cba7f5be43e0f7f3d1/wal-000000030 (ops 143-146)
I20260812 06:17:02.327271  9660 log.cc:1079] T dd20a58864a749cba7f5be43e0f7f3d1 P ebe50f99c71b44b39d6f5a752fb05739: Deleting log segment in path: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515417207375-9491-0/minicluster-data/ts-0-root/wals/dd20a58864a749cba7f5be43e0f7f3d1/wal-000000031 (ops 147-151)
I20260812 06:17:02.327325  9660 log.cc:1079] T dd20a58864a749cba7f5be43e0f7f3d1 P ebe50f99c71b44b39d6f5a752fb05739: Deleting log segment in path: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515417207375-9491-0/minicluster-data/ts-0-root/wals/dd20a58864a749cba7f5be43e0f7f3d1/wal-000000032 (ops 152-156)
I20260812 06:17:02.327379  9660 log.cc:1079] T dd20a58864a749cba7f5be43e0f7f3d1 P ebe50f99c71b44b39d6f5a752fb05739: Deleting log segment in path: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515417207375-9491-0/minicluster-data/ts-0-root/wals/dd20a58864a749cba7f5be43e0f7f3d1/wal-000000033 (ops 157-161)
I20260812 06:17:02.327419  9660 log.cc:1079] T dd20a58864a749cba7f5be43e0f7f3d1 P ebe50f99c71b44b39d6f5a752fb05739: Deleting log segment in path: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515417207375-9491-0/minicluster-data/ts-0-root/wals/dd20a58864a749cba7f5be43e0f7f3d1/wal-000000034 (ops 162-166)
I20260812 06:17:02.327461  9660 log.cc:1079] T dd20a58864a749cba7f5be43e0f7f3d1 P ebe50f99c71b44b39d6f5a752fb05739: Deleting log segment in path: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515417207375-9491-0/minicluster-data/ts-0-root/wals/dd20a58864a749cba7f5be43e0f7f3d1/wal-000000035 (ops 167-170)
I20260812 06:17:02.327503  9660 log.cc:1079] T dd20a58864a749cba7f5be43e0f7f3d1 P ebe50f99c71b44b39d6f5a752fb05739: Deleting log segment in path: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515417207375-9491-0/minicluster-data/ts-0-root/wals/dd20a58864a749cba7f5be43e0f7f3d1/wal-000000036 (ops 171-175)
I20260812 06:17:02.327544  9660 log.cc:1079] T dd20a58864a749cba7f5be43e0f7f3d1 P ebe50f99c71b44b39d6f5a752fb05739: Deleting log segment in path: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515417207375-9491-0/minicluster-data/ts-0-root/wals/dd20a58864a749cba7f5be43e0f7f3d1/wal-000000037 (ops 176-180)
I20260812 06:17:02.327585  9660 log.cc:1079] T dd20a58864a749cba7f5be43e0f7f3d1 P ebe50f99c71b44b39d6f5a752fb05739: Deleting log segment in path: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515417207375-9491-0/minicluster-data/ts-0-root/wals/dd20a58864a749cba7f5be43e0f7f3d1/wal-000000038 (ops 181-185)
I20260812 06:17:02.327626  9660 log.cc:1079] T dd20a58864a749cba7f5be43e0f7f3d1 P ebe50f99c71b44b39d6f5a752fb05739: Deleting log segment in path: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515417207375-9491-0/minicluster-data/ts-0-root/wals/dd20a58864a749cba7f5be43e0f7f3d1/wal-000000039 (ops 186-190)
I20260812 06:17:02.356335  9660 maintenance_manager.cc:643] P ebe50f99c71b44b39d6f5a752fb05739: LogGCOp(dd20a58864a749cba7f5be43e0f7f3d1) complete. Timing: real 0.029s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:17:02.356889  9766 maintenance_manager.cc:419] P ebe50f99c71b44b39d6f5a752fb05739: Scheduling FlushDeltaMemStoresOp(dd20a58864a749cba7f5be43e0f7f3d1): perf score=3.181125
I20260812 06:17:02.374796  9660 maintenance_manager.cc:643] P ebe50f99c71b44b39d6f5a752fb05739: FlushDeltaMemStoresOp(dd20a58864a749cba7f5be43e0f7f3d1) complete. Timing: real 0.018s	user 0.006s	sys 0.009s Metrics: {"bytes_written":4512902,"delete_count":0,"lbm_write_time_us":7090,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:02.375252  9766 maintenance_manager.cc:419] P ebe50f99c71b44b39d6f5a752fb05739: Scheduling UndoDeltaBlockGCOp(dd20a58864a749cba7f5be43e0f7f3d1): 483 bytes on disk
I20260812 06:17:02.375655  9660 maintenance_manager.cc:643] P ebe50f99c71b44b39d6f5a752fb05739: UndoDeltaBlockGCOp(dd20a58864a749cba7f5be43e0f7f3d1) 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:17:02.376181  9766 maintenance_manager.cc:419] P ebe50f99c71b44b39d6f5a752fb05739: Scheduling FlushDeltaMemStoresOp(dd20a58864a749cba7f5be43e0f7f3d1): perf score=2.188937
I20260812 06:17:02.386454  9660 maintenance_manager.cc:643] P ebe50f99c71b44b39d6f5a752fb05739: FlushDeltaMemStoresOp(dd20a58864a749cba7f5be43e0f7f3d1) complete. Timing: real 0.010s	user 0.005s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4031,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:02.386947  9766 maintenance_manager.cc:419] P ebe50f99c71b44b39d6f5a752fb05739: Scheduling MajorDeltaCompactionOp(dd20a58864a749cba7f5be43e0f7f3d1): perf score=1.000000
I20260812 06:17:02.530217  9491 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.043s	user 1.818s	sys 0.167s
I20260812 06:17:02.562036  9660 maintenance_manager.cc:643] P ebe50f99c71b44b39d6f5a752fb05739: MajorDeltaCompactionOp(dd20a58864a749cba7f5be43e0f7f3d1) complete. Timing: real 0.175s	user 0.136s	sys 0.036s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877329,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"lbm_read_time_us":13511,"lbm_reads_lt_1ms":670,"lbm_write_time_us":37689,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2432,"update_count":3000}
I20260812 06:17:02.562538  9766 maintenance_manager.cc:419] P ebe50f99c71b44b39d6f5a752fb05739: Scheduling FlushDeltaMemStoresOp(dd20a58864a749cba7f5be43e0f7f3d1): perf score=10.126437
I20260812 06:17:02.594399  9491 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.064s	user 0.002s	sys 0.000s
I20260812 06:17:02.595024  9491 tablet_server.cc:179] TabletServer@127.9.68.193:0 shutting down...
I20260812 06:17:02.633790  9660 maintenance_manager.cc:643] P ebe50f99c71b44b39d6f5a752fb05739: FlushDeltaMemStoresOp(dd20a58864a749cba7f5be43e0f7f3d1) complete. Timing: real 0.071s	user 0.028s	sys 0.000s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":12243,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:02.634469  9491 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:02.634886  9491 tablet_replica.cc:333] T dd20a58864a749cba7f5be43e0f7f3d1 P ebe50f99c71b44b39d6f5a752fb05739: stopping tablet replica
I20260812 06:17:02.635120  9491 raft_consensus.cc:2243] T dd20a58864a749cba7f5be43e0f7f3d1 P ebe50f99c71b44b39d6f5a752fb05739 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:02.635380  9491 raft_consensus.cc:2272] T dd20a58864a749cba7f5be43e0f7f3d1 P ebe50f99c71b44b39d6f5a752fb05739 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:02.650259  9491 tablet_server.cc:196] TabletServer@127.9.68.193:0 shutdown complete.
I20260812 06:17:02.655200  9491 master.cc:562] Master@127.9.68.254:42953 shutting down...
I20260812 06:17:02.658701  9491 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 2bfda2d0d5244bfcb2b5f984e406f12e [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:02.658864  9491 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 2bfda2d0d5244bfcb2b5f984e406f12e [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:02.658919  9491 tablet_replica.cc:333] T 00000000000000000000000000000000 P 2bfda2d0d5244bfcb2b5f984e406f12e: stopping tablet replica
I20260812 06:17:02.671229  9491 master.cc:584] Master@127.9.68.254:42953 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5563 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:17:02.795186  9491 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.9.68.254:40003
I20260812 06:17:02.795567  9491 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:02.797997  9831 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:02.798041  9825 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:02.798157  9491 server_base.cc:1061] running on GCE node
W20260812 06:17:02.798128  9828 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:02.798374  9491 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:02.798473  9491 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:02.798501  9491 hybrid_clock.cc:648] HybridClock initialized: now 1786515422798500 us; error 0 us; skew 500 ppm
I20260812 06:17:02.799360  9491 webserver.cc:533] Webserver started at http://127.9.68.254:46195/ using document root <none> and password file <none>
I20260812 06:17:02.799551  9491 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:02.799625  9491 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:02.799708  9491 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:02.800127  9491 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515417207375-9491-0/minicluster-data/master-0-root/instance:
uuid: "41f5689aadae4cf5a5555d4a7f9efb87"
format_stamp: "Formatted at 2026-08-12 06:17:02 on dist-test-slave-04bb"
I20260812 06:17:02.801793  9491 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:17:02.802793  9841 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:02.803076  9491 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:17:02.803177  9491 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515417207375-9491-0/minicluster-data/master-0-root
uuid: "41f5689aadae4cf5a5555d4a7f9efb87"
format_stamp: "Formatted at 2026-08-12 06:17:02 on dist-test-slave-04bb"
I20260812 06:17:02.803269  9491 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515417207375-9491-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515417207375-9491-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515417207375-9491-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:02.821098  9491 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:02.821498  9491 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:02.825783  9491 rpc_server.cc:307] RPC server started. Bound to: 127.9.68.254:40003
I20260812 06:17:02.831183  9933 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.9.68.254:40003 every 8 connection(s)
I20260812 06:17:02.831647  9934 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:02.833436  9934 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 41f5689aadae4cf5a5555d4a7f9efb87: Bootstrap starting.
I20260812 06:17:02.834151  9934 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 41f5689aadae4cf5a5555d4a7f9efb87: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:02.835038  9934 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 41f5689aadae4cf5a5555d4a7f9efb87: No bootstrap required, opened a new log
I20260812 06:17:02.835386  9934 raft_consensus.cc:359] T 00000000000000000000000000000000 P 41f5689aadae4cf5a5555d4a7f9efb87 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "41f5689aadae4cf5a5555d4a7f9efb87" member_type: VOTER }
I20260812 06:17:02.835469  9934 raft_consensus.cc:385] T 00000000000000000000000000000000 P 41f5689aadae4cf5a5555d4a7f9efb87 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:02.835491  9934 raft_consensus.cc:740] T 00000000000000000000000000000000 P 41f5689aadae4cf5a5555d4a7f9efb87 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 41f5689aadae4cf5a5555d4a7f9efb87, State: Initialized, Role: FOLLOWER
I20260812 06:17:02.835598  9934 consensus_queue.cc:260] T 00000000000000000000000000000000 P 41f5689aadae4cf5a5555d4a7f9efb87 [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: "41f5689aadae4cf5a5555d4a7f9efb87" member_type: VOTER }
I20260812 06:17:02.835654  9934 raft_consensus.cc:399] T 00000000000000000000000000000000 P 41f5689aadae4cf5a5555d4a7f9efb87 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:02.835676  9934 raft_consensus.cc:493] T 00000000000000000000000000000000 P 41f5689aadae4cf5a5555d4a7f9efb87 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:02.835711  9934 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 41f5689aadae4cf5a5555d4a7f9efb87 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:02.836338  9934 raft_consensus.cc:515] T 00000000000000000000000000000000 P 41f5689aadae4cf5a5555d4a7f9efb87 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "41f5689aadae4cf5a5555d4a7f9efb87" member_type: VOTER }
I20260812 06:17:02.836445  9934 leader_election.cc:304] T 00000000000000000000000000000000 P 41f5689aadae4cf5a5555d4a7f9efb87 [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: 41f5689aadae4cf5a5555d4a7f9efb87; no voters: 
I20260812 06:17:02.836658  9934 leader_election.cc:290] T 00000000000000000000000000000000 P 41f5689aadae4cf5a5555d4a7f9efb87 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:02.836750  9942 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 41f5689aadae4cf5a5555d4a7f9efb87 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:02.836994  9942 raft_consensus.cc:697] T 00000000000000000000000000000000 P 41f5689aadae4cf5a5555d4a7f9efb87 [term 1 LEADER]: Becoming Leader. State: Replica: 41f5689aadae4cf5a5555d4a7f9efb87, State: Running, Role: LEADER
I20260812 06:17:02.837126  9942 consensus_queue.cc:237] T 00000000000000000000000000000000 P 41f5689aadae4cf5a5555d4a7f9efb87 [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: "41f5689aadae4cf5a5555d4a7f9efb87" member_type: VOTER }
I20260812 06:17:02.837174  9934 sys_catalog.cc:565] T 00000000000000000000000000000000 P 41f5689aadae4cf5a5555d4a7f9efb87 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:02.837565  9944 sys_catalog.cc:455] T 00000000000000000000000000000000 P 41f5689aadae4cf5a5555d4a7f9efb87 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "41f5689aadae4cf5a5555d4a7f9efb87" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "41f5689aadae4cf5a5555d4a7f9efb87" member_type: VOTER } }
I20260812 06:17:02.837668  9944 sys_catalog.cc:458] T 00000000000000000000000000000000 P 41f5689aadae4cf5a5555d4a7f9efb87 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:02.837584  9945 sys_catalog.cc:455] T 00000000000000000000000000000000 P 41f5689aadae4cf5a5555d4a7f9efb87 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 41f5689aadae4cf5a5555d4a7f9efb87. Latest consensus state: current_term: 1 leader_uuid: "41f5689aadae4cf5a5555d4a7f9efb87" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "41f5689aadae4cf5a5555d4a7f9efb87" member_type: VOTER } }
I20260812 06:17:02.837980  9945 sys_catalog.cc:458] T 00000000000000000000000000000000 P 41f5689aadae4cf5a5555d4a7f9efb87 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:02.837992  9951 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:02.838914  9951 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:02.839146  9491 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:02.840734  9951 catalog_manager.cc:1383] Generated new cluster ID: 823a0023a6874910b42da84ce1b18526
I20260812 06:17:02.840792  9951 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:02.871822  9951 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:02.872464  9951 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:02.878641  9951 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 41f5689aadae4cf5a5555d4a7f9efb87: Generated new TSK 0
I20260812 06:17:02.878835  9951 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:02.903898  9491 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:02.906267  9970 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:02.906334  9971 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:02.906366  9491 server_base.cc:1061] running on GCE node
W20260812 06:17:02.906594  9975 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:02.906919  9491 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:02.906965  9491 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:02.906980  9491 hybrid_clock.cc:648] HybridClock initialized: now 1786515422906980 us; error 0 us; skew 500 ppm
I20260812 06:17:02.907779  9491 webserver.cc:533] Webserver started at http://127.9.68.193:39525/ using document root <none> and password file <none>
I20260812 06:17:02.907935  9491 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:02.907979  9491 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:02.908085  9491 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:02.908447  9491 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515417207375-9491-0/minicluster-data/ts-0-root/instance:
uuid: "b1a4f415163648979a8ee7c0c3638e63"
format_stamp: "Formatted at 2026-08-12 06:17:02 on dist-test-slave-04bb"
I20260812 06:17:02.909965  9491 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:02.910826  9982 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:02.911077  9491 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:02.911166  9491 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515417207375-9491-0/minicluster-data/ts-0-root
uuid: "b1a4f415163648979a8ee7c0c3638e63"
format_stamp: "Formatted at 2026-08-12 06:17:02 on dist-test-slave-04bb"
I20260812 06:17:02.911254  9491 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515417207375-9491-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515417207375-9491-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515417207375-9491-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:02.919976  9491 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:02.920336  9491 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:02.920696  9491 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:02.921147  9491 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:02.921217  9491 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:02.921273  9491 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:02.921356  9491 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:02.926208  9491 rpc_server.cc:307] RPC server started. Bound to: 127.9.68.193:39567
I20260812 06:17:02.926854 10087 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.9.68.193:39567 every 8 connection(s)
I20260812 06:17:02.931797 10088 heartbeater.cc:344] Connected to a master server at 127.9.68.254:40003
I20260812 06:17:02.931892 10088 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:02.932080 10088 heartbeater.cc:507] Master 127.9.68.254:40003 requested a full tablet report, sending...
I20260812 06:17:02.932726  9869 ts_manager.cc:194] Registered new tserver with Master: b1a4f415163648979a8ee7c0c3638e63 (127.9.68.193:39567)
I20260812 06:17:02.933398  9869 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:48468
I20260812 06:17:02.933691  9491 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.006694632s
I20260812 06:17:02.941180  9869 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:48482:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:17:02.950115 10033 tablet_service.cc:1511] Processing CreateTablet for tablet da5160d3288e4c458cceb28946c70c3d (DEFAULT_TABLE table=heavy-update-compaction-test [id=f857c7760ac244128b25f5160aed8734]), partition=
I20260812 06:17:02.950461 10033 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet da5160d3288e4c458cceb28946c70c3d. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:02.952643 10112 tablet_bootstrap.cc:492] T da5160d3288e4c458cceb28946c70c3d P b1a4f415163648979a8ee7c0c3638e63: Bootstrap starting.
I20260812 06:17:02.953503 10112 tablet_bootstrap.cc:654] T da5160d3288e4c458cceb28946c70c3d P b1a4f415163648979a8ee7c0c3638e63: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:02.954535 10112 tablet_bootstrap.cc:492] T da5160d3288e4c458cceb28946c70c3d P b1a4f415163648979a8ee7c0c3638e63: No bootstrap required, opened a new log
I20260812 06:17:02.954646 10112 ts_tablet_manager.cc:1403] T da5160d3288e4c458cceb28946c70c3d P b1a4f415163648979a8ee7c0c3638e63: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:17:02.955156 10112 raft_consensus.cc:359] T da5160d3288e4c458cceb28946c70c3d P b1a4f415163648979a8ee7c0c3638e63 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b1a4f415163648979a8ee7c0c3638e63" member_type: VOTER last_known_addr { host: "127.9.68.193" port: 39567 } }
I20260812 06:17:02.955284 10112 raft_consensus.cc:385] T da5160d3288e4c458cceb28946c70c3d P b1a4f415163648979a8ee7c0c3638e63 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:02.955328 10112 raft_consensus.cc:740] T da5160d3288e4c458cceb28946c70c3d P b1a4f415163648979a8ee7c0c3638e63 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: b1a4f415163648979a8ee7c0c3638e63, State: Initialized, Role: FOLLOWER
I20260812 06:17:02.955478 10112 consensus_queue.cc:260] T da5160d3288e4c458cceb28946c70c3d P b1a4f415163648979a8ee7c0c3638e63 [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: "b1a4f415163648979a8ee7c0c3638e63" member_type: VOTER last_known_addr { host: "127.9.68.193" port: 39567 } }
I20260812 06:17:02.955590 10112 raft_consensus.cc:399] T da5160d3288e4c458cceb28946c70c3d P b1a4f415163648979a8ee7c0c3638e63 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:02.955643 10112 raft_consensus.cc:493] T da5160d3288e4c458cceb28946c70c3d P b1a4f415163648979a8ee7c0c3638e63 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:02.955705 10112 raft_consensus.cc:3060] T da5160d3288e4c458cceb28946c70c3d P b1a4f415163648979a8ee7c0c3638e63 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:02.956439 10112 raft_consensus.cc:515] T da5160d3288e4c458cceb28946c70c3d P b1a4f415163648979a8ee7c0c3638e63 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b1a4f415163648979a8ee7c0c3638e63" member_type: VOTER last_known_addr { host: "127.9.68.193" port: 39567 } }
I20260812 06:17:02.956633 10112 leader_election.cc:304] T da5160d3288e4c458cceb28946c70c3d P b1a4f415163648979a8ee7c0c3638e63 [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: b1a4f415163648979a8ee7c0c3638e63; no voters: 
I20260812 06:17:02.956856 10112 leader_election.cc:290] T da5160d3288e4c458cceb28946c70c3d P b1a4f415163648979a8ee7c0c3638e63 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:02.956990 10114 raft_consensus.cc:2804] T da5160d3288e4c458cceb28946c70c3d P b1a4f415163648979a8ee7c0c3638e63 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:02.957209 10112 ts_tablet_manager.cc:1434] T da5160d3288e4c458cceb28946c70c3d P b1a4f415163648979a8ee7c0c3638e63: Time spent starting tablet: real 0.002s	user 0.001s	sys 0.002s
I20260812 06:17:02.957211 10088 heartbeater.cc:499] Master 127.9.68.254:40003 was elected leader, sending a full tablet report...
I20260812 06:17:02.957283 10114 raft_consensus.cc:697] T da5160d3288e4c458cceb28946c70c3d P b1a4f415163648979a8ee7c0c3638e63 [term 1 LEADER]: Becoming Leader. State: Replica: b1a4f415163648979a8ee7c0c3638e63, State: Running, Role: LEADER
I20260812 06:17:02.957459 10114 consensus_queue.cc:237] T da5160d3288e4c458cceb28946c70c3d P b1a4f415163648979a8ee7c0c3638e63 [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: "b1a4f415163648979a8ee7c0c3638e63" member_type: VOTER last_known_addr { host: "127.9.68.193" port: 39567 } }
I20260812 06:17:02.958755  9869 catalog_manager.cc:5719] T da5160d3288e4c458cceb28946c70c3d P b1a4f415163648979a8ee7c0c3638e63 reported cstate change: term changed from 0 to 1, leader changed from <none> to b1a4f415163648979a8ee7c0c3638e63 (127.9.68.193). New cstate: current_term: 1 leader_uuid: "b1a4f415163648979a8ee7c0c3638e63" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b1a4f415163648979a8ee7c0c3638e63" member_type: VOTER last_known_addr { host: "127.9.68.193" port: 39567 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:03.019047  9491 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.053s	user 0.015s	sys 0.007s
I20260812 06:17:03.177891 10089 maintenance_manager.cc:419] P b1a4f415163648979a8ee7c0c3638e63: Scheduling FlushMRSOp(da5160d3288e4c458cceb28946c70c3d): perf score=20.047128
I20260812 06:17:03.351094  9993 maintenance_manager.cc:643] P b1a4f415163648979a8ee7c0c3638e63: FlushMRSOp(da5160d3288e4c458cceb28946c70c3d) complete. Timing: real 0.173s	user 0.112s	sys 0.056s Metrics: {"bytes_written":12307492,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":64,"dirs.run_cpu_time_us":221,"dirs.run_wall_time_us":939,"drs_written":1,"lbm_read_time_us":36,"lbm_reads_lt_1ms":4,"lbm_write_time_us":47302,"lbm_writes_lt_1ms":857,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"update_count":1500}
I20260812 06:17:03.351682 10089 maintenance_manager.cc:419] P b1a4f415163648979a8ee7c0c3638e63: Scheduling LogGCOp(da5160d3288e4c458cceb28946c70c3d): free 20743880 bytes of WAL
I20260812 06:17:03.351915  9993 log_reader.cc:385] T da5160d3288e4c458cceb28946c70c3d: removed 2 log segments from log reader
I20260812 06:17:03.351963  9993 log.cc:1079] T da5160d3288e4c458cceb28946c70c3d P b1a4f415163648979a8ee7c0c3638e63: Deleting log segment in path: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515417207375-9491-0/minicluster-data/ts-0-root/wals/da5160d3288e4c458cceb28946c70c3d/wal-000000001 (ops 1-6)
I20260812 06:17:03.351992  9993 log.cc:1079] T da5160d3288e4c458cceb28946c70c3d P b1a4f415163648979a8ee7c0c3638e63: Deleting log segment in path: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515417207375-9491-0/minicluster-data/ts-0-root/wals/da5160d3288e4c458cceb28946c70c3d/wal-000000002 (ops 7-11)
I20260812 06:17:03.356364  9993 maintenance_manager.cc:643] P b1a4f415163648979a8ee7c0c3638e63: LogGCOp(da5160d3288e4c458cceb28946c70c3d) complete. Timing: real 0.004s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:17:03.356710 10089 maintenance_manager.cc:419] P b1a4f415163648979a8ee7c0c3638e63: Scheduling UndoDeltaBlockGCOp(da5160d3288e4c458cceb28946c70c3d): 20513812 bytes on disk
I20260812 06:17:03.357103  9993 maintenance_manager.cc:643] P b1a4f415163648979a8ee7c0c3638e63: UndoDeltaBlockGCOp(da5160d3288e4c458cceb28946c70c3d) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4}
I20260812 06:17:03.357456 10089 maintenance_manager.cc:419] P b1a4f415163648979a8ee7c0c3638e63: Scheduling FlushDeltaMemStoresOp(da5160d3288e4c458cceb28946c70c3d): perf score=2.188937
I20260812 06:17:03.370044  9993 maintenance_manager.cc:643] P b1a4f415163648979a8ee7c0c3638e63: FlushDeltaMemStoresOp(da5160d3288e4c458cceb28946c70c3d) complete. Timing: real 0.012s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4836,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:03.370482 10089 maintenance_manager.cc:419] P b1a4f415163648979a8ee7c0c3638e63: Scheduling MajorDeltaCompactionOp(da5160d3288e4c458cceb28946c70c3d): perf score=1.000000
I20260812 06:17:03.534984  9993 maintenance_manager.cc:643] P b1a4f415163648979a8ee7c0c3638e63: MajorDeltaCompactionOp(da5160d3288e4c458cceb28946c70c3d) complete. Timing: real 0.164s	user 0.127s	sys 0.035s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713273,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":515,"lbm_read_time_us":12240,"lbm_reads_lt_1ms":468,"lbm_write_time_us":27184,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2176,"thread_start_us":344,"threads_started":5,"update_count":2000}
I20260812 06:17:03.535786 10089 maintenance_manager.cc:419] P b1a4f415163648979a8ee7c0c3638e63: Scheduling FlushDeltaMemStoresOp(da5160d3288e4c458cceb28946c70c3d): perf score=11.118625
I20260812 06:17:03.576622  9993 maintenance_manager.cc:643] P b1a4f415163648979a8ee7c0c3638e63: FlushDeltaMemStoresOp(da5160d3288e4c458cceb28946c70c3d) complete. Timing: real 0.040s	user 0.024s	sys 0.016s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":17698,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:03.577109 10089 maintenance_manager.cc:419] P b1a4f415163648979a8ee7c0c3638e63: Scheduling FlushDeltaMemStoresOp(da5160d3288e4c458cceb28946c70c3d): perf score=2.188937
I20260812 06:17:03.590446  9993 maintenance_manager.cc:643] P b1a4f415163648979a8ee7c0c3638e63: FlushDeltaMemStoresOp(da5160d3288e4c458cceb28946c70c3d) complete. Timing: real 0.013s	user 0.007s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5137,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:03.590848 10089 maintenance_manager.cc:419] P b1a4f415163648979a8ee7c0c3638e63: Scheduling MajorDeltaCompactionOp(da5160d3288e4c458cceb28946c70c3d): perf score=1.000000
I20260812 06:17:03.765316  9993 maintenance_manager.cc:643] P b1a4f415163648979a8ee7c0c3638e63: MajorDeltaCompactionOp(da5160d3288e4c458cceb28946c70c3d) complete. Timing: real 0.174s	user 0.117s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713263,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":190,"lbm_read_time_us":10554,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24685,"lbm_writes_lt_1ms":443,"mutex_wait_us":41,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":103296,"update_count":2000}
I20260812 06:17:03.767632 10089 maintenance_manager.cc:419] P b1a4f415163648979a8ee7c0c3638e63: Scheduling FlushDeltaMemStoresOp(da5160d3288e4c458cceb28946c70c3d): perf score=14.095187
I20260812 06:17:03.816138  9993 maintenance_manager.cc:643] P b1a4f415163648979a8ee7c0c3638e63: FlushDeltaMemStoresOp(da5160d3288e4c458cceb28946c70c3d) complete. Timing: real 0.048s	user 0.023s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21516,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:03.816663 10089 maintenance_manager.cc:419] P b1a4f415163648979a8ee7c0c3638e63: Scheduling FlushDeltaMemStoresOp(da5160d3288e4c458cceb28946c70c3d): perf score=2.188937
I20260812 06:17:03.832439  9993 maintenance_manager.cc:643] P b1a4f415163648979a8ee7c0c3638e63: FlushDeltaMemStoresOp(da5160d3288e4c458cceb28946c70c3d) complete. Timing: real 0.016s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6315,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:03.832911 10089 maintenance_manager.cc:419] P b1a4f415163648979a8ee7c0c3638e63: Scheduling MajorDeltaCompactionOp(da5160d3288e4c458cceb28946c70c3d): perf score=1.000000
I20260812 06:17:03.992571  9993 maintenance_manager.cc:643] P b1a4f415163648979a8ee7c0c3638e63: MajorDeltaCompactionOp(da5160d3288e4c458cceb28946c70c3d) complete. Timing: real 0.159s	user 0.109s	sys 0.041s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":273,"lbm_read_time_us":10074,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29785,"lbm_writes_lt_1ms":543,"mutex_wait_us":35,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11392,"update_count":2500}
I20260812 06:17:03.993438 10089 maintenance_manager.cc:419] P b1a4f415163648979a8ee7c0c3638e63: Scheduling FlushDeltaMemStoresOp(da5160d3288e4c458cceb28946c70c3d): perf score=14.095187
I20260812 06:17:04.052755  9993 maintenance_manager.cc:643] P b1a4f415163648979a8ee7c0c3638e63: FlushDeltaMemStoresOp(da5160d3288e4c458cceb28946c70c3d) complete. Timing: real 0.059s	user 0.032s	sys 0.016s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":22125,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:04.053272 10089 maintenance_manager.cc:419] P b1a4f415163648979a8ee7c0c3638e63: Scheduling FlushDeltaMemStoresOp(da5160d3288e4c458cceb28946c70c3d): perf score=2.188937
I20260812 06:17:04.066089  9993 maintenance_manager.cc:643] P b1a4f415163648979a8ee7c0c3638e63: FlushDeltaMemStoresOp(da5160d3288e4c458cceb28946c70c3d) complete. Timing: real 0.013s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5086,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:04.066841 10089 maintenance_manager.cc:419] P b1a4f415163648979a8ee7c0c3638e63: Scheduling MajorDeltaCompactionOp(da5160d3288e4c458cceb28946c70c3d): perf score=1.000000
I20260812 06:17:04.319080  9993 maintenance_manager.cc:643] P b1a4f415163648979a8ee7c0c3638e63: MajorDeltaCompactionOp(da5160d3288e4c458cceb28946c70c3d) complete. Timing: real 0.252s	user 0.127s	sys 0.038s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815686,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":573,"lbm_read_time_us":14241,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32441,"lbm_writes_lt_1ms":543,"mutex_wait_us":283,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2500}
I20260812 06:17:04.320281 10089 maintenance_manager.cc:419] P b1a4f415163648979a8ee7c0c3638e63: Scheduling FlushDeltaMemStoresOp(da5160d3288e4c458cceb28946c70c3d): perf score=20.048312
I20260812 06:17:04.429503  9993 maintenance_manager.cc:643] P b1a4f415163648979a8ee7c0c3638e63: FlushDeltaMemStoresOp(da5160d3288e4c458cceb28946c70c3d) complete. Timing: real 0.109s	user 0.038s	sys 0.021s Metrics: {"bytes_written":22194303,"delete_count":0,"lbm_write_time_us":26467,"lbm_writes_lt_1ms":544,"reinsert_count":0,"update_count":2705}
I20260812 06:17:04.429996 10089 maintenance_manager.cc:419] P b1a4f415163648979a8ee7c0c3638e63: Scheduling FlushDeltaMemStoresOp(da5160d3288e4c458cceb28946c70c3d): perf score=9.134250
I20260812 06:17:04.538163  9993 maintenance_manager.cc:643] P b1a4f415163648979a8ee7c0c3638e63: FlushDeltaMemStoresOp(da5160d3288e4c458cceb28946c70c3d) complete. Timing: real 0.108s	user 0.018s	sys 0.011s Metrics: {"bytes_written":10625502,"delete_count":0,"lbm_write_time_us":12537,"lbm_writes_lt_1ms":262,"reinsert_count":0,"update_count":1295}
I20260812 06:17:04.539196 10089 maintenance_manager.cc:419] P b1a4f415163648979a8ee7c0c3638e63: Scheduling FlushDeltaMemStoresOp(da5160d3288e4c458cceb28946c70c3d): perf score=7.149875
I20260812 06:17:04.638630  9993 maintenance_manager.cc:643] P b1a4f415163648979a8ee7c0c3638e63: FlushDeltaMemStoresOp(da5160d3288e4c458cceb28946c70c3d) complete. Timing: real 0.099s	user 0.016s	sys 0.012s Metrics: {"bytes_written":8451225,"delete_count":0,"lbm_write_time_us":11896,"lbm_writes_lt_1ms":209,"reinsert_count":0,"update_count":1030}
I20260812 06:17:04.639366 10089 maintenance_manager.cc:419] P b1a4f415163648979a8ee7c0c3638e63: Scheduling FlushDeltaMemStoresOp(da5160d3288e4c458cceb28946c70c3d): perf score=9.134250
I20260812 06:17:04.738775  9993 maintenance_manager.cc:643] P b1a4f415163648979a8ee7c0c3638e63: FlushDeltaMemStoresOp(da5160d3288e4c458cceb28946c70c3d) complete. Timing: real 0.099s	user 0.025s	sys 0.003s Metrics: {"bytes_written":10830626,"delete_count":0,"lbm_write_time_us":12603,"lbm_writes_lt_1ms":267,"reinsert_count":0,"update_count":1320}
I20260812 06:17:04.739688 10089 maintenance_manager.cc:419] P b1a4f415163648979a8ee7c0c3638e63: Scheduling FlushDeltaMemStoresOp(da5160d3288e4c458cceb28946c70c3d): perf score=6.157687
I20260812 06:17:04.840708  9993 maintenance_manager.cc:643] P b1a4f415163648979a8ee7c0c3638e63: FlushDeltaMemStoresOp(da5160d3288e4c458cceb28946c70c3d) complete. Timing: real 0.101s	user 0.016s	sys 0.008s Metrics: {"bytes_written":8246103,"delete_count":0,"lbm_write_time_us":9570,"lbm_writes_lt_1ms":204,"reinsert_count":0,"update_count":1005}
I20260812 06:17:04.841454 10089 maintenance_manager.cc:419] P b1a4f415163648979a8ee7c0c3638e63: Scheduling FlushDeltaMemStoresOp(da5160d3288e4c458cceb28946c70c3d): perf score=8.142062
I20260812 06:17:04.943640  9993 maintenance_manager.cc:643] P b1a4f415163648979a8ee7c0c3638e63: FlushDeltaMemStoresOp(da5160d3288e4c458cceb28946c70c3d) complete. Timing: real 0.102s	user 0.011s	sys 0.016s Metrics: {"bytes_written":9394777,"delete_count":0,"lbm_write_time_us":12055,"lbm_writes_lt_1ms":232,"reinsert_count":0,"update_count":1145}
I20260812 06:17:04.944303 10089 maintenance_manager.cc:419] P b1a4f415163648979a8ee7c0c3638e63: Scheduling FlushDeltaMemStoresOp(da5160d3288e4c458cceb28946c70c3d): perf score=7.149875
I20260812 06:17:05.045012  9993 maintenance_manager.cc:643] P b1a4f415163648979a8ee7c0c3638e63: FlushDeltaMemStoresOp(da5160d3288e4c458cceb28946c70c3d) complete. Timing: real 0.101s	user 0.021s	sys 0.007s Metrics: {"bytes_written":9148636,"delete_count":0,"lbm_write_time_us":11529,"lbm_writes_lt_1ms":226,"reinsert_count":0,"update_count":1115}
I20260812 06:17:05.045753 10089 maintenance_manager.cc:419] P b1a4f415163648979a8ee7c0c3638e63: Scheduling FlushDeltaMemStoresOp(da5160d3288e4c458cceb28946c70c3d): perf score=9.134250
I20260812 06:17:05.150964  9993 maintenance_manager.cc:643] P b1a4f415163648979a8ee7c0c3638e63: FlushDeltaMemStoresOp(da5160d3288e4c458cceb28946c70c3d) complete. Timing: real 0.105s	user 0.018s	sys 0.013s Metrics: {"bytes_written":11363934,"delete_count":0,"lbm_write_time_us":13639,"lbm_writes_lt_1ms":280,"reinsert_count":0,"update_count":1385}
I20260812 06:17:05.151602 10089 maintenance_manager.cc:419] P b1a4f415163648979a8ee7c0c3638e63: Scheduling FlushDeltaMemStoresOp(da5160d3288e4c458cceb28946c70c3d): perf score=6.157687
I20260812 06:17:05.252633  9993 maintenance_manager.cc:643] P b1a4f415163648979a8ee7c0c3638e63: FlushDeltaMemStoresOp(da5160d3288e4c458cceb28946c70c3d) complete. Timing: real 0.101s	user 0.022s	sys 0.007s Metrics: {"bytes_written":8246104,"delete_count":0,"lbm_write_time_us":12288,"lbm_writes_lt_1ms":204,"reinsert_count":0,"update_count":1005}
I20260812 06:17:05.253427 10089 maintenance_manager.cc:419] P b1a4f415163648979a8ee7c0c3638e63: Scheduling FlushDeltaMemStoresOp(da5160d3288e4c458cceb28946c70c3d): perf score=9.134250
I20260812 06:17:05.340728  9993 maintenance_manager.cc:643] P b1a4f415163648979a8ee7c0c3638e63: FlushDeltaMemStoresOp(da5160d3288e4c458cceb28946c70c3d) complete. Timing: real 0.087s	user 0.016s	sys 0.016s Metrics: {"bytes_written":10912677,"delete_count":0,"lbm_write_time_us":13013,"lbm_writes_lt_1ms":269,"reinsert_count":0,"update_count":1330}
I20260812 06:17:05.341305 10089 maintenance_manager.cc:419] P b1a4f415163648979a8ee7c0c3638e63: Scheduling FlushDeltaMemStoresOp(da5160d3288e4c458cceb28946c70c3d): perf score=8.142062
I20260812 06:17:05.415736  9993 maintenance_manager.cc:643] P b1a4f415163648979a8ee7c0c3638e63: FlushDeltaMemStoresOp(da5160d3288e4c458cceb28946c70c3d) complete. Timing: real 0.074s	user 0.017s	sys 0.012s Metrics: {"bytes_written":9558878,"delete_count":0,"lbm_write_time_us":13810,"lbm_writes_lt_1ms":236,"reinsert_count":0,"update_count":1165}
I20260812 06:17:05.416436 10089 maintenance_manager.cc:419] P b1a4f415163648979a8ee7c0c3638e63: Scheduling FlushDeltaMemStoresOp(da5160d3288e4c458cceb28946c70c3d): perf score=2.188937
I20260812 06:17:05.507509  9993 maintenance_manager.cc:643] P b1a4f415163648979a8ee7c0c3638e63: FlushDeltaMemStoresOp(da5160d3288e4c458cceb28946c70c3d) complete. Timing: real 0.091s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4225735,"delete_count":0,"lbm_write_time_us":4606,"lbm_writes_lt_1ms":106,"reinsert_count":0,"update_count":515}
I20260812 06:17:05.508358 10089 maintenance_manager.cc:419] P b1a4f415163648979a8ee7c0c3638e63: Scheduling FlushDeltaMemStoresOp(da5160d3288e4c458cceb28946c70c3d): perf score=10.126437
I20260812 06:17:05.609731  9993 maintenance_manager.cc:643] P b1a4f415163648979a8ee7c0c3638e63: FlushDeltaMemStoresOp(da5160d3288e4c458cceb28946c70c3d) complete. Timing: real 0.101s	user 0.026s	sys 0.004s Metrics: {"bytes_written":11856229,"delete_count":0,"lbm_write_time_us":12681,"lbm_writes_lt_1ms":292,"reinsert_count":0,"update_count":1445}
I20260812 06:17:05.610407 10089 maintenance_manager.cc:419] P b1a4f415163648979a8ee7c0c3638e63: Scheduling FlushDeltaMemStoresOp(da5160d3288e4c458cceb28946c70c3d): perf score=7.149875
I20260812 06:17:05.711709  9993 maintenance_manager.cc:643] P b1a4f415163648979a8ee7c0c3638e63: FlushDeltaMemStoresOp(da5160d3288e4c458cceb28946c70c3d) complete. Timing: real 0.101s	user 0.016s	sys 0.007s Metrics: {"bytes_written":8533275,"delete_count":0,"lbm_write_time_us":10141,"lbm_writes_lt_1ms":211,"reinsert_count":0,"update_count":1040}
I20260812 06:17:05.712280 10089 maintenance_manager.cc:419] P b1a4f415163648979a8ee7c0c3638e63: Scheduling FlushDeltaMemStoresOp(da5160d3288e4c458cceb28946c70c3d): perf score=7.149875
I20260812 06:17:05.813961  9993 maintenance_manager.cc:643] P b1a4f415163648979a8ee7c0c3638e63: FlushDeltaMemStoresOp(da5160d3288e4c458cceb28946c70c3d) complete. Timing: real 0.102s	user 0.014s	sys 0.008s Metrics: {"bytes_written":8615323,"delete_count":0,"lbm_write_time_us":9935,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:17:05.814530 10089 maintenance_manager.cc:419] P b1a4f415163648979a8ee7c0c3638e63: Scheduling FlushDeltaMemStoresOp(da5160d3288e4c458cceb28946c70c3d): perf score=10.126437
I20260812 06:17:05.917253  9993 maintenance_manager.cc:643] P b1a4f415163648979a8ee7c0c3638e63: FlushDeltaMemStoresOp(da5160d3288e4c458cceb28946c70c3d) complete. Timing: real 0.103s	user 0.016s	sys 0.023s Metrics: {"bytes_written":11897249,"delete_count":0,"lbm_write_time_us":17134,"lbm_writes_lt_1ms":293,"reinsert_count":0,"update_count":1450}
I20260812 06:17:05.918349 10089 maintenance_manager.cc:419] P b1a4f415163648979a8ee7c0c3638e63: Scheduling FlushDeltaMemStoresOp(da5160d3288e4c458cceb28946c70c3d): perf score=6.157687
I20260812 06:17:06.020466  9993 maintenance_manager.cc:643] P b1a4f415163648979a8ee7c0c3638e63: FlushDeltaMemStoresOp(da5160d3288e4c458cceb28946c70c3d) complete. Timing: real 0.102s	user 0.021s	sys 0.008s Metrics: {"bytes_written":8205077,"delete_count":0,"lbm_write_time_us":13708,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:17:06.021165 10089 maintenance_manager.cc:419] P b1a4f415163648979a8ee7c0c3638e63: Scheduling FlushDeltaMemStoresOp(da5160d3288e4c458cceb28946c70c3d): perf score=7.149875
I20260812 06:17:06.120250  9993 maintenance_manager.cc:643] P b1a4f415163648979a8ee7c0c3638e63: FlushDeltaMemStoresOp(da5160d3288e4c458cceb28946c70c3d) complete. Timing: real 0.099s	user 0.019s	sys 0.008s Metrics: {"bytes_written":8615323,"delete_count":0,"lbm_write_time_us":12384,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:17:06.120973 10089 maintenance_manager.cc:419] P b1a4f415163648979a8ee7c0c3638e63: Scheduling FlushDeltaMemStoresOp(da5160d3288e4c458cceb28946c70c3d): perf score=6.157687
I20260812 06:17:06.225562  9993 maintenance_manager.cc:643] P b1a4f415163648979a8ee7c0c3638e63: FlushDeltaMemStoresOp(da5160d3288e4c458cceb28946c70c3d) complete. Timing: real 0.104s	user 0.016s	sys 0.004s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":8621,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:17:06.226418 10089 maintenance_manager.cc:419] P b1a4f415163648979a8ee7c0c3638e63: Scheduling FlushDeltaMemStoresOp(da5160d3288e4c458cceb28946c70c3d): perf score=10.126437
I20260812 06:17:06.326045  9993 maintenance_manager.cc:643] P b1a4f415163648979a8ee7c0c3638e63: FlushDeltaMemStoresOp(da5160d3288e4c458cceb28946c70c3d) complete. Timing: real 0.099s	user 0.019s	sys 0.024s Metrics: {"bytes_written":11897249,"delete_count":0,"lbm_write_time_us":19347,"lbm_writes_lt_1ms":293,"reinsert_count":0,"update_count":1450}
I20260812 06:17:06.327013 10089 maintenance_manager.cc:419] P b1a4f415163648979a8ee7c0c3638e63: Scheduling FlushDeltaMemStoresOp(da5160d3288e4c458cceb28946c70c3d): perf score=6.157687
I20260812 06:17:06.425722  9993 maintenance_manager.cc:643] P b1a4f415163648979a8ee7c0c3638e63: FlushDeltaMemStoresOp(da5160d3288e4c458cceb28946c70c3d) complete. Timing: real 0.099s	user 0.007s	sys 0.020s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":12536,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:17:06.426632 10089 maintenance_manager.cc:419] P b1a4f415163648979a8ee7c0c3638e63: Scheduling FlushDeltaMemStoresOp(da5160d3288e4c458cceb28946c70c3d): perf score=7.149875
I20260812 06:17:06.531549  9993 maintenance_manager.cc:643] P b1a4f415163648979a8ee7c0c3638e63: FlushDeltaMemStoresOp(da5160d3288e4c458cceb28946c70c3d) complete. Timing: real 0.105s	user 0.012s	sys 0.010s Metrics: {"bytes_written":8615323,"delete_count":0,"lbm_write_time_us":10320,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:17:06.532140 10089 maintenance_manager.cc:419] P b1a4f415163648979a8ee7c0c3638e63: Scheduling FlushDeltaMemStoresOp(da5160d3288e4c458cceb28946c70c3d): perf score=10.126437
I20260812 06:17:06.632513  9993 maintenance_manager.cc:643] P b1a4f415163648979a8ee7c0c3638e63: FlushDeltaMemStoresOp(da5160d3288e4c458cceb28946c70c3d) complete. Timing: real 0.100s	user 0.022s	sys 0.011s Metrics: {"bytes_written":11897250,"delete_count":0,"lbm_write_time_us":16669,"lbm_writes_lt_1ms":293,"reinsert_count":0,"update_count":1450}
I20260812 06:17:06.633495 10089 maintenance_manager.cc:419] P b1a4f415163648979a8ee7c0c3638e63: Scheduling FlushDeltaMemStoresOp(da5160d3288e4c458cceb28946c70c3d): perf score=6.157687
I20260812 06:17:06.730001  9993 maintenance_manager.cc:643] P b1a4f415163648979a8ee7c0c3638e63: FlushDeltaMemStoresOp(da5160d3288e4c458cceb28946c70c3d) complete. Timing: real 0.096s	user 0.016s	sys 0.012s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":13867,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:17:06.731628 10089 maintenance_manager.cc:419] P b1a4f415163648979a8ee7c0c3638e63: Scheduling FlushDeltaMemStoresOp(da5160d3288e4c458cceb28946c70c3d): perf score=6.157687
I20260812 06:17:06.754489  9993 maintenance_manager.cc:643] P b1a4f415163648979a8ee7c0c3638e63: FlushDeltaMemStoresOp(da5160d3288e4c458cceb28946c70c3d) complete. Timing: real 0.023s	user 0.020s	sys 0.000s Metrics: {"bytes_written":8205079,"delete_count":0,"lbm_write_time_us":10275,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:17:06.755051 10089 maintenance_manager.cc:419] P b1a4f415163648979a8ee7c0c3638e63: Scheduling FlushDeltaMemStoresOp(da5160d3288e4c458cceb28946c70c3d): perf score=2.188937
I20260812 06:17:06.815594  9993 maintenance_manager.cc:643] P b1a4f415163648979a8ee7c0c3638e63: FlushDeltaMemStoresOp(da5160d3288e4c458cceb28946c70c3d) complete. Timing: real 0.060s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5123,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:06.816098 10089 maintenance_manager.cc:419] P b1a4f415163648979a8ee7c0c3638e63: Scheduling FlushDeltaMemStoresOp(da5160d3288e4c458cceb28946c70c3d): perf score=3.181125
I20260812 06:17:06.840461  9993 maintenance_manager.cc:643] P b1a4f415163648979a8ee7c0c3638e63: FlushDeltaMemStoresOp(da5160d3288e4c458cceb28946c70c3d) complete. Timing: real 0.024s	user 0.008s	sys 0.008s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":7608,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:06.840963 10089 maintenance_manager.cc:419] P b1a4f415163648979a8ee7c0c3638e63: Scheduling FlushDeltaMemStoresOp(da5160d3288e4c458cceb28946c70c3d): perf score=2.188937
I20260812 06:17:06.855935  9993 maintenance_manager.cc:643] P b1a4f415163648979a8ee7c0c3638e63: FlushDeltaMemStoresOp(da5160d3288e4c458cceb28946c70c3d) complete. Timing: real 0.015s	user 0.005s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":7248,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:06.856402 10089 maintenance_manager.cc:419] P b1a4f415163648979a8ee7c0c3638e63: Scheduling FlushMRSOp(da5160d3288e4c458cceb28946c70c3d): perf score=2.187753
I20260812 06:17:06.897173  9993 maintenance_manager.cc:643] P b1a4f415163648979a8ee7c0c3638e63: FlushMRSOp(da5160d3288e4c458cceb28946c70c3d) complete. Timing: real 0.041s	user 0.036s	sys 0.004s Metrics: {"bytes_written":3324565,"cfile_init":1,"dirs.queue_time_us":210,"dirs.run_cpu_time_us":247,"dirs.run_wall_time_us":1410,"drs_written":1,"lbm_read_time_us":45,"lbm_reads_lt_1ms":4,"lbm_write_time_us":3917,"lbm_writes_lt_1ms":49,"peak_mem_usage":0,"rows_written":81,"thread_start_us":95,"threads_started":1}
I20260812 06:17:06.898520 10089 maintenance_manager.cc:419] P b1a4f415163648979a8ee7c0c3638e63: Scheduling LogGCOp(da5160d3288e4c458cceb28946c70c3d): free 332561219 bytes of WAL
I20260812 06:17:06.898999  9993 log_reader.cc:385] T da5160d3288e4c458cceb28946c70c3d: removed 33 log segments from log reader
I20260812 06:17:06.899094  9993 log.cc:1079] T da5160d3288e4c458cceb28946c70c3d P b1a4f415163648979a8ee7c0c3638e63: Deleting log segment in path: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515417207375-9491-0/minicluster-data/ts-0-root/wals/da5160d3288e4c458cceb28946c70c3d/wal-000000003 (ops 12-16)
I20260812 06:17:06.899168  9993 log.cc:1079] T da5160d3288e4c458cceb28946c70c3d P b1a4f415163648979a8ee7c0c3638e63: Deleting log segment in path: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515417207375-9491-0/minicluster-data/ts-0-root/wals/da5160d3288e4c458cceb28946c70c3d/wal-000000004 (ops 17-21)
I20260812 06:17:06.899212  9993 log.cc:1079] T da5160d3288e4c458cceb28946c70c3d P b1a4f415163648979a8ee7c0c3638e63: Deleting log segment in path: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515417207375-9491-0/minicluster-data/ts-0-root/wals/da5160d3288e4c458cceb28946c70c3d/wal-000000005 (ops 22-26)
I20260812 06:17:06.899255  9993 log.cc:1079] T da5160d3288e4c458cceb28946c70c3d P b1a4f415163648979a8ee7c0c3638e63: Deleting log segment in path: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515417207375-9491-0/minicluster-data/ts-0-root/wals/da5160d3288e4c458cceb28946c70c3d/wal-000000006 (ops 27-31)
I20260812 06:17:06.899300  9993 log.cc:1079] T da5160d3288e4c458cceb28946c70c3d P b1a4f415163648979a8ee7c0c3638e63: Deleting log segment in path: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515417207375-9491-0/minicluster-data/ts-0-root/wals/da5160d3288e4c458cceb28946c70c3d/wal-000000007 (ops 32-36)
I20260812 06:17:06.899343  9993 log.cc:1079] T da5160d3288e4c458cceb28946c70c3d P b1a4f415163648979a8ee7c0c3638e63: Deleting log segment in path: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515417207375-9491-0/minicluster-data/ts-0-root/wals/da5160d3288e4c458cceb28946c70c3d/wal-000000008 (ops 37-40)
I20260812 06:17:06.899384  9993 log.cc:1079] T da5160d3288e4c458cceb28946c70c3d P b1a4f415163648979a8ee7c0c3638e63: Deleting log segment in path: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515417207375-9491-0/minicluster-data/ts-0-root/wals/da5160d3288e4c458cceb28946c70c3d/wal-000000009 (ops 41-45)
I20260812 06:17:06.899427  9993 log.cc:1079] T da5160d3288e4c458cceb28946c70c3d P b1a4f415163648979a8ee7c0c3638e63: Deleting log segment in path: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515417207375-9491-0/minicluster-data/ts-0-root/wals/da5160d3288e4c458cceb28946c70c3d/wal-000000010 (ops 46-50)
I20260812 06:17:06.899469  9993 log.cc:1079] T da5160d3288e4c458cceb28946c70c3d P b1a4f415163648979a8ee7c0c3638e63: Deleting log segment in path: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515417207375-9491-0/minicluster-data/ts-0-root/wals/da5160d3288e4c458cceb28946c70c3d/wal-000000011 (ops 51-55)
I20260812 06:17:06.899509  9993 log.cc:1079] T da5160d3288e4c458cceb28946c70c3d P b1a4f415163648979a8ee7c0c3638e63: Deleting log segment in path: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515417207375-9491-0/minicluster-data/ts-0-root/wals/da5160d3288e4c458cceb28946c70c3d/wal-000000012 (ops 56-60)
I20260812 06:17:06.899552  9993 log.cc:1079] T da5160d3288e4c458cceb28946c70c3d P b1a4f415163648979a8ee7c0c3638e63: Deleting log segment in path: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515417207375-9491-0/minicluster-data/ts-0-root/wals/da5160d3288e4c458cceb28946c70c3d/wal-000000013 (ops 61-65)
I20260812 06:17:06.899593  9993 log.cc:1079] T da5160d3288e4c458cceb28946c70c3d P b1a4f415163648979a8ee7c0c3638e63: Deleting log segment in path: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515417207375-9491-0/minicluster-data/ts-0-root/wals/da5160d3288e4c458cceb28946c70c3d/wal-000000014 (ops 66-70)
I20260812 06:17:06.899667  9993 log.cc:1079] T da5160d3288e4c458cceb28946c70c3d P b1a4f415163648979a8ee7c0c3638e63: Deleting log segment in path: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515417207375-9491-0/minicluster-data/ts-0-root/wals/da5160d3288e4c458cceb28946c70c3d/wal-000000015 (ops 71-75)
I20260812 06:17:06.899708  9993 log.cc:1079] T da5160d3288e4c458cceb28946c70c3d P b1a4f415163648979a8ee7c0c3638e63: Deleting log segment in path: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515417207375-9491-0/minicluster-data/ts-0-root/wals/da5160d3288e4c458cceb28946c70c3d/wal-000000016 (ops 76-80)
I20260812 06:17:06.899751  9993 log.cc:1079] T da5160d3288e4c458cceb28946c70c3d P b1a4f415163648979a8ee7c0c3638e63: Deleting log segment in path: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515417207375-9491-0/minicluster-data/ts-0-root/wals/da5160d3288e4c458cceb28946c70c3d/wal-000000017 (ops 81-84)
I20260812 06:17:06.899796  9993 log.cc:1079] T da5160d3288e4c458cceb28946c70c3d P b1a4f415163648979a8ee7c0c3638e63: Deleting log segment in path: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515417207375-9491-0/minicluster-data/ts-0-root/wals/da5160d3288e4c458cceb28946c70c3d/wal-000000018 (ops 85-89)
I20260812 06:17:06.899837  9993 log.cc:1079] T da5160d3288e4c458cceb28946c70c3d P b1a4f415163648979a8ee7c0c3638e63: Deleting log segment in path: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515417207375-9491-0/minicluster-data/ts-0-root/wals/da5160d3288e4c458cceb28946c70c3d/wal-000000019 (ops 90-94)
I20260812 06:17:06.899879  9993 log.cc:1079] T da5160d3288e4c458cceb28946c70c3d P b1a4f415163648979a8ee7c0c3638e63: Deleting log segment in path: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515417207375-9491-0/minicluster-data/ts-0-root/wals/da5160d3288e4c458cceb28946c70c3d/wal-000000020 (ops 95-99)
I20260812 06:17:06.899920  9993 log.cc:1079] T da5160d3288e4c458cceb28946c70c3d P b1a4f415163648979a8ee7c0c3638e63: Deleting log segment in path: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515417207375-9491-0/minicluster-data/ts-0-root/wals/da5160d3288e4c458cceb28946c70c3d/wal-000000021 (ops 100-104)
I20260812 06:17:06.899962  9993 log.cc:1079] T da5160d3288e4c458cceb28946c70c3d P b1a4f415163648979a8ee7c0c3638e63: Deleting log segment in path: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515417207375-9491-0/minicluster-data/ts-0-root/wals/da5160d3288e4c458cceb28946c70c3d/wal-000000022 (ops 105-109)
I20260812 06:17:06.900003  9993 log.cc:1079] T da5160d3288e4c458cceb28946c70c3d P b1a4f415163648979a8ee7c0c3638e63: Deleting log segment in path: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515417207375-9491-0/minicluster-data/ts-0-root/wals/da5160d3288e4c458cceb28946c70c3d/wal-000000023 (ops 110-114)
I20260812 06:17:06.900049  9993 log.cc:1079] T da5160d3288e4c458cceb28946c70c3d P b1a4f415163648979a8ee7c0c3638e63: Deleting log segment in path: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515417207375-9491-0/minicluster-data/ts-0-root/wals/da5160d3288e4c458cceb28946c70c3d/wal-000000024 (ops 115-118)
I20260812 06:17:06.900099  9993 log.cc:1079] T da5160d3288e4c458cceb28946c70c3d P b1a4f415163648979a8ee7c0c3638e63: Deleting log segment in path: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515417207375-9491-0/minicluster-data/ts-0-root/wals/da5160d3288e4c458cceb28946c70c3d/wal-000000025 (ops 119-123)
I20260812 06:17:06.900139  9993 log.cc:1079] T da5160d3288e4c458cceb28946c70c3d P b1a4f415163648979a8ee7c0c3638e63: Deleting log segment in path: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515417207375-9491-0/minicluster-data/ts-0-root/wals/da5160d3288e4c458cceb28946c70c3d/wal-000000026 (ops 124-128)
I20260812 06:17:06.900182  9993 log.cc:1079] T da5160d3288e4c458cceb28946c70c3d P b1a4f415163648979a8ee7c0c3638e63: Deleting log segment in path: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515417207375-9491-0/minicluster-data/ts-0-root/wals/da5160d3288e4c458cceb28946c70c3d/wal-000000027 (ops 129-133)
I20260812 06:17:06.900223  9993 log.cc:1079] T da5160d3288e4c458cceb28946c70c3d P b1a4f415163648979a8ee7c0c3638e63: Deleting log segment in path: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515417207375-9491-0/minicluster-data/ts-0-root/wals/da5160d3288e4c458cceb28946c70c3d/wal-000000028 (ops 134-138)
I20260812 06:17:06.900265  9993 log.cc:1079] T da5160d3288e4c458cceb28946c70c3d P b1a4f415163648979a8ee7c0c3638e63: Deleting log segment in path: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515417207375-9491-0/minicluster-data/ts-0-root/wals/da5160d3288e4c458cceb28946c70c3d/wal-000000029 (ops 139-142)
I20260812 06:17:06.900307  9993 log.cc:1079] T da5160d3288e4c458cceb28946c70c3d P b1a4f415163648979a8ee7c0c3638e63: Deleting log segment in path: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515417207375-9491-0/minicluster-data/ts-0-root/wals/da5160d3288e4c458cceb28946c70c3d/wal-000000030 (ops 143-147)
I20260812 06:17:06.900349  9993 log.cc:1079] T da5160d3288e4c458cceb28946c70c3d P b1a4f415163648979a8ee7c0c3638e63: Deleting log segment in path: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515417207375-9491-0/minicluster-data/ts-0-root/wals/da5160d3288e4c458cceb28946c70c3d/wal-000000031 (ops 148-152)
I20260812 06:17:06.900389  9993 log.cc:1079] T da5160d3288e4c458cceb28946c70c3d P b1a4f415163648979a8ee7c0c3638e63: Deleting log segment in path: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515417207375-9491-0/minicluster-data/ts-0-root/wals/da5160d3288e4c458cceb28946c70c3d/wal-000000032 (ops 153-157)
I20260812 06:17:06.900432  9993 log.cc:1079] T da5160d3288e4c458cceb28946c70c3d P b1a4f415163648979a8ee7c0c3638e63: Deleting log segment in path: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515417207375-9491-0/minicluster-data/ts-0-root/wals/da5160d3288e4c458cceb28946c70c3d/wal-000000033 (ops 158-162)
I20260812 06:17:06.900477  9993 log.cc:1079] T da5160d3288e4c458cceb28946c70c3d P b1a4f415163648979a8ee7c0c3638e63: Deleting log segment in path: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515417207375-9491-0/minicluster-data/ts-0-root/wals/da5160d3288e4c458cceb28946c70c3d/wal-000000034 (ops 163-166)
I20260812 06:17:06.900540  9993 log.cc:1079] T da5160d3288e4c458cceb28946c70c3d P b1a4f415163648979a8ee7c0c3638e63: Deleting log segment in path: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515417207375-9491-0/minicluster-data/ts-0-root/wals/da5160d3288e4c458cceb28946c70c3d/wal-000000035 (ops 167-171)
I20260812 06:17:06.981916  9993 maintenance_manager.cc:643] P b1a4f415163648979a8ee7c0c3638e63: LogGCOp(da5160d3288e4c458cceb28946c70c3d) complete. Timing: real 0.083s	user 0.003s	sys 0.079s Metrics: {}
I20260812 06:17:06.982364 10089 maintenance_manager.cc:419] P b1a4f415163648979a8ee7c0c3638e63: Scheduling UndoDeltaBlockGCOp(da5160d3288e4c458cceb28946c70c3d): 1050 bytes on disk
I20260812 06:17:06.982896  9993 maintenance_manager.cc:643] P b1a4f415163648979a8ee7c0c3638e63: UndoDeltaBlockGCOp(da5160d3288e4c458cceb28946c70c3d) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":91,"lbm_reads_lt_1ms":4}
I20260812 06:17:06.983388 10089 maintenance_manager.cc:419] P b1a4f415163648979a8ee7c0c3638e63: Scheduling FlushDeltaMemStoresOp(da5160d3288e4c458cceb28946c70c3d): perf score=7.149875
I20260812 06:17:07.011560  9993 maintenance_manager.cc:643] P b1a4f415163648979a8ee7c0c3638e63: FlushDeltaMemStoresOp(da5160d3288e4c458cceb28946c70c3d) complete. Timing: real 0.028s	user 0.018s	sys 0.007s Metrics: {"bytes_written":8615322,"delete_count":0,"lbm_write_time_us":12312,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:17:07.012055 10089 maintenance_manager.cc:419] P b1a4f415163648979a8ee7c0c3638e63: Scheduling LogGCOp(da5160d3288e4c458cceb28946c70c3d): free 12018006 bytes of WAL
I20260812 06:17:07.012253  9993 log_reader.cc:385] T da5160d3288e4c458cceb28946c70c3d: removed 1 log segments from log reader
I20260812 06:17:07.012303  9993 log.cc:1079] T da5160d3288e4c458cceb28946c70c3d P b1a4f415163648979a8ee7c0c3638e63: Deleting log segment in path: /tmp/dist-test-taskENCBt4/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515417207375-9491-0/minicluster-data/ts-0-root/wals/da5160d3288e4c458cceb28946c70c3d/wal-000000036 (ops 172-176)
I20260812 06:17:07.014712  9993 maintenance_manager.cc:643] P b1a4f415163648979a8ee7c0c3638e63: LogGCOp(da5160d3288e4c458cceb28946c70c3d) complete. Timing: real 0.002s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:17:07.015059 10089 maintenance_manager.cc:419] P b1a4f415163648979a8ee7c0c3638e63: Scheduling FlushDeltaMemStoresOp(da5160d3288e4c458cceb28946c70c3d): perf score=2.188937
I20260812 06:17:07.028565  9993 maintenance_manager.cc:643] P b1a4f415163648979a8ee7c0c3638e63: FlushDeltaMemStoresOp(da5160d3288e4c458cceb28946c70c3d) complete. Timing: real 0.013s	user 0.012s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4362,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:07.029122 10089 maintenance_manager.cc:419] P b1a4f415163648979a8ee7c0c3638e63: Scheduling MajorDeltaCompactionOp(da5160d3288e4c458cceb28946c70c3d): perf score=1.000000
I20260812 06:17:07.705426  9491 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.686s	user 1.662s	sys 0.177s
I20260812 06:17:08.752692 10010 rpcz_store.cc:275] Call kudu.tserver.TabletServerService.Scan from 127.0.0.1:41738 (request call id 202) took 1046 ms. Trace:
I20260812 06:17:08.752833 10010 rpcz_store.cc:276] 0812 06:17:07.706696 (+     0us) service_pool.cc:167] Inserting onto call queue
0812 06:17:07.706773 (+    77us) service_pool.cc:224] Handling call
0812 06:17:07.706992 (+   219us) tablet_service.cc:2890] Created scanner 3ab69518c0ac4d1590d36d32b1087e9d for tablet da5160d3288e4c458cceb28946c70c3d, query id is f7034dc7d97b4c0bae3d4371c90fbc56
0812 06:17:07.707472 (+   480us) tablet_service.cc:3030] Creating iterator
0812 06:17:07.707509 (+    37us) tablet_service.cc:3408] Waiting safe time to advance
0812 06:17:07.707534 (+    25us) tablet_service.cc:3415] Waiting for operations to commit
0812 06:17:07.707554 (+    20us) tablet_service.cc:3431] All operations in snapshot committed. Waited for 33 microseconds
0812 06:17:07.707634 (+    80us) tablet_service.cc:3055] Iterator created
0812 06:17:08.687160 (+979526us) tablet_service.cc:3077] Iterator init: OK
0812 06:17:08.687212 (+    52us) tablet_service.cc:3120] has_more: true
0812 06:17:08.687276 (+    64us) tablet_service.cc:3137] Continuing scan request
0812 06:17:08.687345 (+    69us) tablet_service.cc:3201] Found scanner 3ab69518c0ac4d1590d36d32b1087e9d for tablet da5160d3288e4c458cceb28946c70c3d, query id is f7034dc7d97b4c0bae3d4371c90fbc56
0812 06:17:08.752674 (+ 65329us) inbound_call.cc:177] Queueing success response
Metrics: {"cfile_cache_hit":33,"cfile_cache_hit_bytes":90420,"cfile_cache_miss":6631,"cfile_cache_miss_bytes":274976008,"cfile_init":4,"delta_iterators_relevant":34,"lbm_read_time_us":125070,"lbm_reads_lt_1ms":6647,"rowset_iterators":2,"scanner_bytes_read":2991789,"spinlock_wait_cycles":896}
W20260812 06:17:08.755406  9491 scanner-internal.cc:458] Time spent opening tablet: real 1.049s	user 0.001s	sys 0.000s
I20260812 06:17:08.757510  9491 heavy-update-compaction-itest.cc:265] Time spent scanning: real 1.052s	user 0.002s	sys 0.000s
I20260812 06:17:08.757988  9491 tablet_server.cc:179] TabletServer@127.9.68.193:0 shutting down...
I20260812 06:17:09.009438  9993 maintenance_manager.cc:643] P b1a4f415163648979a8ee7c0c3638e63: MajorDeltaCompactionOp(da5160d3288e4c458cceb28946c70c3d) complete. Timing: real 1.980s	user 0.937s	sys 1.037s Metrics: {"cfile_cache_miss":6660,"cfile_cache_miss_bytes":275066199,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":30,"delta_iterators_relevant":30,"dirs.queue_time_us":585,"lbm_read_time_us":110979,"lbm_reads_lt_1ms":6688,"lbm_write_time_us":424743,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":6647,"peak_mem_usage":821136792,"reinsert_count":0,"spinlock_wait_cycles":110592,"thread_start_us":503,"threads_started":8,"update_count":33000,"wal-append.queue_time_us":204}
I20260812 06:17:09.010200  9491 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:09.010479  9491 tablet_replica.cc:333] T da5160d3288e4c458cceb28946c70c3d P b1a4f415163648979a8ee7c0c3638e63: stopping tablet replica
I20260812 06:17:09.010655  9491 raft_consensus.cc:2243] T da5160d3288e4c458cceb28946c70c3d P b1a4f415163648979a8ee7c0c3638e63 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:09.010846  9491 raft_consensus.cc:2272] T da5160d3288e4c458cceb28946c70c3d P b1a4f415163648979a8ee7c0c3638e63 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:09.031888  9491 tablet_server.cc:196] TabletServer@127.9.68.193:0 shutdown complete.
I20260812 06:17:10.067179  9491 master.cc:562] Master@127.9.68.254:40003 shutting down...
I20260812 06:17:10.070775  9491 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 41f5689aadae4cf5a5555d4a7f9efb87 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:10.070971  9491 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 41f5689aadae4cf5a5555d4a7f9efb87 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:10.071061  9491 tablet_replica.cc:333] T 00000000000000000000000000000000 P 41f5689aadae4cf5a5555d4a7f9efb87: stopping tablet replica
I20260812 06:17:10.083617  9491 master.cc:584] Master@127.9.68.254:40003 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (7391 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (12956 ms total)

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