[==========] 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:20:16.371740 14598 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.14.65.190:34681
I20260812 06:20:16.372795 14598 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:20:16.373414 14598 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:16.379531 14604 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:16.379869 14603 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:20:16.380331 14606 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:20:16.380513 14598 server_base.cc:1061] running on GCE node
I20260812 06:20:16.380950 14598 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:16.381073 14598 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:20:16.381119 14598 hybrid_clock.cc:648] HybridClock initialized: now 1786515616381115 us; error 0 us; skew 500 ppm
I20260812 06:20:16.382982 14598 webserver.cc:533] Webserver started at http://127.14.65.190:42621/ using document root <none> and password file <none>
I20260812 06:20:16.383548 14598 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:16.383642 14598 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:16.383906 14598 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:16.385624 14598 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616361105-14598-0/minicluster-data/master-0-root/instance:
uuid: "c8c45ebc7f60401da9cf49d208a628d7"
format_stamp: "Formatted at 2026-08-12 06:20:16 on dist-test-slave-8w9v"
I20260812 06:20:16.389256 14598 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.001s	sys 0.003s
I20260812 06:20:16.391381 14613 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:20:16.392414 14598 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.001s
I20260812 06:20:16.392544 14598 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616361105-14598-0/minicluster-data/master-0-root
uuid: "c8c45ebc7f60401da9cf49d208a628d7"
format_stamp: "Formatted at 2026-08-12 06:20:16 on dist-test-slave-8w9v"
I20260812 06:20:16.392653 14598 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616361105-14598-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616361105-14598-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616361105-14598-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:20:16.411339 14598 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:16.412024 14598 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:20:16.412271 14598 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:16.419785 14598 rpc_server.cc:307] RPC server started. Bound to: 127.14.65.190:34681
I20260812 06:20:16.419838 14672 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.14.65.190:34681 every 8 connection(s)
I20260812 06:20:16.422391 14673 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:20:16.428339 14673 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P c8c45ebc7f60401da9cf49d208a628d7: Bootstrap starting.
I20260812 06:20:16.430881 14673 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P c8c45ebc7f60401da9cf49d208a628d7: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:16.431883 14673 log.cc:826] T 00000000000000000000000000000000 P c8c45ebc7f60401da9cf49d208a628d7: Log is configured to *not* fsync() on all Append() calls
I20260812 06:20:16.433794 14673 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P c8c45ebc7f60401da9cf49d208a628d7: No bootstrap required, opened a new log
I20260812 06:20:16.436754 14673 raft_consensus.cc:359] T 00000000000000000000000000000000 P c8c45ebc7f60401da9cf49d208a628d7 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c8c45ebc7f60401da9cf49d208a628d7" member_type: VOTER }
I20260812 06:20:16.436928 14673 raft_consensus.cc:385] T 00000000000000000000000000000000 P c8c45ebc7f60401da9cf49d208a628d7 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:16.437011 14673 raft_consensus.cc:740] T 00000000000000000000000000000000 P c8c45ebc7f60401da9cf49d208a628d7 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: c8c45ebc7f60401da9cf49d208a628d7, State: Initialized, Role: FOLLOWER
I20260812 06:20:16.437634 14673 consensus_queue.cc:260] T 00000000000000000000000000000000 P c8c45ebc7f60401da9cf49d208a628d7 [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: "c8c45ebc7f60401da9cf49d208a628d7" member_type: VOTER }
I20260812 06:20:16.437824 14673 raft_consensus.cc:399] T 00000000000000000000000000000000 P c8c45ebc7f60401da9cf49d208a628d7 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:16.437911 14673 raft_consensus.cc:493] T 00000000000000000000000000000000 P c8c45ebc7f60401da9cf49d208a628d7 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:16.438087 14673 raft_consensus.cc:3060] T 00000000000000000000000000000000 P c8c45ebc7f60401da9cf49d208a628d7 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:16.438951 14673 raft_consensus.cc:515] T 00000000000000000000000000000000 P c8c45ebc7f60401da9cf49d208a628d7 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c8c45ebc7f60401da9cf49d208a628d7" member_type: VOTER }
I20260812 06:20:16.439409 14673 leader_election.cc:304] T 00000000000000000000000000000000 P c8c45ebc7f60401da9cf49d208a628d7 [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: c8c45ebc7f60401da9cf49d208a628d7; no voters: 
I20260812 06:20:16.439764 14673 leader_election.cc:290] T 00000000000000000000000000000000 P c8c45ebc7f60401da9cf49d208a628d7 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:16.439937 14676 raft_consensus.cc:2804] T 00000000000000000000000000000000 P c8c45ebc7f60401da9cf49d208a628d7 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:16.440220 14676 raft_consensus.cc:697] T 00000000000000000000000000000000 P c8c45ebc7f60401da9cf49d208a628d7 [term 1 LEADER]: Becoming Leader. State: Replica: c8c45ebc7f60401da9cf49d208a628d7, State: Running, Role: LEADER
I20260812 06:20:16.440627 14676 consensus_queue.cc:237] T 00000000000000000000000000000000 P c8c45ebc7f60401da9cf49d208a628d7 [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: "c8c45ebc7f60401da9cf49d208a628d7" member_type: VOTER }
I20260812 06:20:16.440933 14673 sys_catalog.cc:565] T 00000000000000000000000000000000 P c8c45ebc7f60401da9cf49d208a628d7 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:16.442579 14678 sys_catalog.cc:455] T 00000000000000000000000000000000 P c8c45ebc7f60401da9cf49d208a628d7 [sys.catalog]: SysCatalogTable state changed. Reason: New leader c8c45ebc7f60401da9cf49d208a628d7. Latest consensus state: current_term: 1 leader_uuid: "c8c45ebc7f60401da9cf49d208a628d7" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c8c45ebc7f60401da9cf49d208a628d7" member_type: VOTER } }
I20260812 06:20:16.442619 14677 sys_catalog.cc:455] T 00000000000000000000000000000000 P c8c45ebc7f60401da9cf49d208a628d7 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "c8c45ebc7f60401da9cf49d208a628d7" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c8c45ebc7f60401da9cf49d208a628d7" member_type: VOTER } }
I20260812 06:20:16.442701 14678 sys_catalog.cc:458] T 00000000000000000000000000000000 P c8c45ebc7f60401da9cf49d208a628d7 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:16.442721 14677 sys_catalog.cc:458] T 00000000000000000000000000000000 P c8c45ebc7f60401da9cf49d208a628d7 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:16.443068 14685 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:16.445794 14685 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:16.446105 14598 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:16.450842 14685 catalog_manager.cc:1383] Generated new cluster ID: 450f398673d2418db21843d0d7fd9e87
I20260812 06:20:16.450922 14685 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:16.465636 14685 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:16.466557 14685 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:16.479699 14685 catalog_manager.cc:6092] T 00000000000000000000000000000000 P c8c45ebc7f60401da9cf49d208a628d7: Generated new TSK 0
I20260812 06:20:16.480541 14685 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:16.511134 14598 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:16.513935 14700 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:20:16.513972 14697 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:20:16.514050 14698 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:20:16.514304 14598 server_base.cc:1061] running on GCE node
I20260812 06:20:16.514482 14598 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:16.514531 14598 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:20:16.514547 14598 hybrid_clock.cc:648] HybridClock initialized: now 1786515616514548 us; error 0 us; skew 500 ppm
I20260812 06:20:16.515543 14598 webserver.cc:533] Webserver started at http://127.14.65.129:42441/ using document root <none> and password file <none>
I20260812 06:20:16.515734 14598 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:16.515784 14598 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:16.515900 14598 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:16.516391 14598 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616361105-14598-0/minicluster-data/ts-0-root/instance:
uuid: "4deaea3dbb994ef7841ee7e2add4661f"
format_stamp: "Formatted at 2026-08-12 06:20:16 on dist-test-slave-8w9v"
I20260812 06:20:16.517987 14598 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:20:16.519008 14706 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:20:16.519272 14598 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.000s
I20260812 06:20:16.519346 14598 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616361105-14598-0/minicluster-data/ts-0-root
uuid: "4deaea3dbb994ef7841ee7e2add4661f"
format_stamp: "Formatted at 2026-08-12 06:20:16 on dist-test-slave-8w9v"
I20260812 06:20:16.519446 14598 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616361105-14598-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616361105-14598-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616361105-14598-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:20:16.533752 14598 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:16.534390 14598 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:16.534951 14598 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:16.535876 14598 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:16.535950 14598 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:16.536037 14598 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:16.536068 14598 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:16.543027 14598 rpc_server.cc:307] RPC server started. Bound to: 127.14.65.129:37705
I20260812 06:20:16.543114 14780 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.14.65.129:37705 every 8 connection(s)
I20260812 06:20:16.553054 14781 heartbeater.cc:344] Connected to a master server at 127.14.65.190:34681
I20260812 06:20:16.553308 14781 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:16.553785 14781 heartbeater.cc:507] Master 127.14.65.190:34681 requested a full tablet report, sending...
I20260812 06:20:16.555258 14633 ts_manager.cc:194] Registered new tserver with Master: 4deaea3dbb994ef7841ee7e2add4661f (127.14.65.129:37705)
I20260812 06:20:16.555964 14598 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.012332632s
I20260812 06:20:16.556690 14633 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:37150
I20260812 06:20:16.565752 14633 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:37152:
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:20:16.580291 14738 tablet_service.cc:1511] Processing CreateTablet for tablet ca29cec422e54676b673d39fc1c23f7e (DEFAULT_TABLE table=heavy-update-compaction-test [id=249d80dbb6154bb3ba9147ac7ad7b4b8]), partition=
I20260812 06:20:16.580803 14738 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet ca29cec422e54676b673d39fc1c23f7e. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:16.583148 14793 tablet_bootstrap.cc:492] T ca29cec422e54676b673d39fc1c23f7e P 4deaea3dbb994ef7841ee7e2add4661f: Bootstrap starting.
I20260812 06:20:16.584417 14793 tablet_bootstrap.cc:654] T ca29cec422e54676b673d39fc1c23f7e P 4deaea3dbb994ef7841ee7e2add4661f: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:16.585667 14793 tablet_bootstrap.cc:492] T ca29cec422e54676b673d39fc1c23f7e P 4deaea3dbb994ef7841ee7e2add4661f: No bootstrap required, opened a new log
I20260812 06:20:16.585754 14793 ts_tablet_manager.cc:1403] T ca29cec422e54676b673d39fc1c23f7e P 4deaea3dbb994ef7841ee7e2add4661f: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:20:16.586275 14793 raft_consensus.cc:359] T ca29cec422e54676b673d39fc1c23f7e P 4deaea3dbb994ef7841ee7e2add4661f [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4deaea3dbb994ef7841ee7e2add4661f" member_type: VOTER last_known_addr { host: "127.14.65.129" port: 37705 } }
I20260812 06:20:16.586383 14793 raft_consensus.cc:385] T ca29cec422e54676b673d39fc1c23f7e P 4deaea3dbb994ef7841ee7e2add4661f [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:16.586406 14793 raft_consensus.cc:740] T ca29cec422e54676b673d39fc1c23f7e P 4deaea3dbb994ef7841ee7e2add4661f [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 4deaea3dbb994ef7841ee7e2add4661f, State: Initialized, Role: FOLLOWER
I20260812 06:20:16.586577 14793 consensus_queue.cc:260] T ca29cec422e54676b673d39fc1c23f7e P 4deaea3dbb994ef7841ee7e2add4661f [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: "4deaea3dbb994ef7841ee7e2add4661f" member_type: VOTER last_known_addr { host: "127.14.65.129" port: 37705 } }
I20260812 06:20:16.586664 14793 raft_consensus.cc:399] T ca29cec422e54676b673d39fc1c23f7e P 4deaea3dbb994ef7841ee7e2add4661f [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:16.586714 14793 raft_consensus.cc:493] T ca29cec422e54676b673d39fc1c23f7e P 4deaea3dbb994ef7841ee7e2add4661f [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:16.586768 14793 raft_consensus.cc:3060] T ca29cec422e54676b673d39fc1c23f7e P 4deaea3dbb994ef7841ee7e2add4661f [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:16.588093 14793 raft_consensus.cc:515] T ca29cec422e54676b673d39fc1c23f7e P 4deaea3dbb994ef7841ee7e2add4661f [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4deaea3dbb994ef7841ee7e2add4661f" member_type: VOTER last_known_addr { host: "127.14.65.129" port: 37705 } }
I20260812 06:20:16.588289 14793 leader_election.cc:304] T ca29cec422e54676b673d39fc1c23f7e P 4deaea3dbb994ef7841ee7e2add4661f [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: 4deaea3dbb994ef7841ee7e2add4661f; no voters: 
I20260812 06:20:16.588557 14793 leader_election.cc:290] T ca29cec422e54676b673d39fc1c23f7e P 4deaea3dbb994ef7841ee7e2add4661f [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:16.588649 14795 raft_consensus.cc:2804] T ca29cec422e54676b673d39fc1c23f7e P 4deaea3dbb994ef7841ee7e2add4661f [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:16.588841 14795 raft_consensus.cc:697] T ca29cec422e54676b673d39fc1c23f7e P 4deaea3dbb994ef7841ee7e2add4661f [term 1 LEADER]: Becoming Leader. State: Replica: 4deaea3dbb994ef7841ee7e2add4661f, State: Running, Role: LEADER
I20260812 06:20:16.588968 14793 ts_tablet_manager.cc:1434] T ca29cec422e54676b673d39fc1c23f7e P 4deaea3dbb994ef7841ee7e2add4661f: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:20:16.589062 14795 consensus_queue.cc:237] T ca29cec422e54676b673d39fc1c23f7e P 4deaea3dbb994ef7841ee7e2add4661f [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: "4deaea3dbb994ef7841ee7e2add4661f" member_type: VOTER last_known_addr { host: "127.14.65.129" port: 37705 } }
I20260812 06:20:16.589187 14781 heartbeater.cc:499] Master 127.14.65.190:34681 was elected leader, sending a full tablet report...
I20260812 06:20:16.592104 14633 catalog_manager.cc:5719] T ca29cec422e54676b673d39fc1c23f7e P 4deaea3dbb994ef7841ee7e2add4661f reported cstate change: term changed from 0 to 1, leader changed from <none> to 4deaea3dbb994ef7841ee7e2add4661f (127.14.65.129). New cstate: current_term: 1 leader_uuid: "4deaea3dbb994ef7841ee7e2add4661f" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4deaea3dbb994ef7841ee7e2add4661f" member_type: VOTER last_known_addr { host: "127.14.65.129" port: 37705 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:16.657446 14598 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.056s	user 0.017s	sys 0.010s
I20260812 06:20:16.794811 14782 maintenance_manager.cc:419] P 4deaea3dbb994ef7841ee7e2add4661f: Scheduling FlushMRSOp(ca29cec422e54676b673d39fc1c23f7e): perf score=19.054940
I20260812 06:20:16.990064 14713 maintenance_manager.cc:643] P 4deaea3dbb994ef7841ee7e2add4661f: FlushMRSOp(ca29cec422e54676b673d39fc1c23f7e) complete. Timing: real 0.195s	user 0.167s	sys 0.024s Metrics: {"bytes_written":13538210,"cfile_init":1,"compiler_manager_pool.queue_time_us":322,"delete_count":0,"dirs.queue_time_us":62,"dirs.run_cpu_time_us":240,"dirs.run_wall_time_us":1354,"drs_written":1,"lbm_read_time_us":75,"lbm_reads_lt_1ms":4,"lbm_write_time_us":50119,"lbm_writes_lt_1ms":787,"mutex_wait_us":1859,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":163072,"thread_start_us":207,"threads_started":1,"update_count":1650}
I20260812 06:20:16.991350 14782 maintenance_manager.cc:419] P 4deaea3dbb994ef7841ee7e2add4661f: Scheduling LogGCOp(ca29cec422e54676b673d39fc1c23f7e): free 20743880 bytes of WAL
I20260812 06:20:16.991662 14713 log_reader.cc:385] T ca29cec422e54676b673d39fc1c23f7e: removed 2 log segments from log reader
I20260812 06:20:16.991743 14713 log.cc:1079] T ca29cec422e54676b673d39fc1c23f7e P 4deaea3dbb994ef7841ee7e2add4661f: Deleting log segment in path: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616361105-14598-0/minicluster-data/ts-0-root/wals/ca29cec422e54676b673d39fc1c23f7e/wal-000000001 (ops 1-6)
I20260812 06:20:16.991809 14713 log.cc:1079] T ca29cec422e54676b673d39fc1c23f7e P 4deaea3dbb994ef7841ee7e2add4661f: Deleting log segment in path: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616361105-14598-0/minicluster-data/ts-0-root/wals/ca29cec422e54676b673d39fc1c23f7e/wal-000000002 (ops 7-11)
I20260812 06:20:16.997505 14713 maintenance_manager.cc:643] P 4deaea3dbb994ef7841ee7e2add4661f: LogGCOp(ca29cec422e54676b673d39fc1c23f7e) complete. Timing: real 0.006s	user 0.000s	sys 0.005s Metrics: {}
I20260812 06:20:16.998051 14782 maintenance_manager.cc:419] P 4deaea3dbb994ef7841ee7e2add4661f: Scheduling UndoDeltaBlockGCOp(ca29cec422e54676b673d39fc1c23f7e): 16411392 bytes on disk
I20260812 06:20:16.998719 14713 maintenance_manager.cc:643] P 4deaea3dbb994ef7841ee7e2add4661f: UndoDeltaBlockGCOp(ca29cec422e54676b673d39fc1c23f7e) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":83,"lbm_reads_lt_1ms":4}
I20260812 06:20:16.999176 14782 maintenance_manager.cc:419] P 4deaea3dbb994ef7841ee7e2add4661f: Scheduling FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e): perf score=5.165500
I20260812 06:20:17.027812 14713 maintenance_manager.cc:643] P 4deaea3dbb994ef7841ee7e2add4661f: FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e) complete. Timing: real 0.028s	user 0.013s	sys 0.011s Metrics: {"bytes_written":6564114,"delete_count":0,"lbm_write_time_us":10479,"lbm_writes_lt_1ms":163,"reinsert_count":0,"update_count":800}
I20260812 06:20:17.028540 14782 maintenance_manager.cc:419] P 4deaea3dbb994ef7841ee7e2add4661f: Scheduling MajorDeltaCompactionOp(ca29cec422e54676b673d39fc1c23f7e): perf score=1.000000
I20260812 06:20:17.205744 14713 maintenance_manager.cc:643] P 4deaea3dbb994ef7841ee7e2add4661f: MajorDeltaCompactionOp(ca29cec422e54676b673d39fc1c23f7e) complete. Timing: real 0.177s	user 0.124s	sys 0.052s Metrics: {"cfile_cache_miss":522,"cfile_cache_miss_bytes":24364446,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1606,"lbm_read_time_us":11522,"lbm_reads_lt_1ms":554,"lbm_write_time_us":30812,"lbm_writes_lt_1ms":533,"mutex_wait_us":267,"peak_mem_usage":61665166,"reinsert_count":0,"spinlock_wait_cycles":768,"thread_start_us":377,"threads_started":5,"update_count":2450}
I20260812 06:20:17.206346 14782 maintenance_manager.cc:419] P 4deaea3dbb994ef7841ee7e2add4661f: Scheduling FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e): perf score=11.118625
I20260812 06:20:17.245805 14713 maintenance_manager.cc:643] P 4deaea3dbb994ef7841ee7e2add4661f: FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e) complete. Timing: real 0.039s	user 0.026s	sys 0.012s Metrics: {"bytes_written":13127979,"delete_count":0,"lbm_write_time_us":16900,"lbm_writes_lt_1ms":323,"reinsert_count":0,"update_count":1600}
I20260812 06:20:17.246392 14782 maintenance_manager.cc:419] P 4deaea3dbb994ef7841ee7e2add4661f: Scheduling FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e): perf score=2.188937
I20260812 06:20:17.259181 14713 maintenance_manager.cc:643] P 4deaea3dbb994ef7841ee7e2add4661f: FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e) complete. Timing: real 0.013s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4863,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:17.259616 14782 maintenance_manager.cc:419] P 4deaea3dbb994ef7841ee7e2add4661f: Scheduling MajorDeltaCompactionOp(ca29cec422e54676b673d39fc1c23f7e): perf score=1.000000
I20260812 06:20:17.390256 14713 maintenance_manager.cc:643] P 4deaea3dbb994ef7841ee7e2add4661f: MajorDeltaCompactionOp(ca29cec422e54676b673d39fc1c23f7e) complete. Timing: real 0.130s	user 0.106s	sys 0.024s Metrics: {"cfile_cache_miss":442,"cfile_cache_miss_bytes":21082512,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":527,"lbm_read_time_us":6994,"lbm_reads_lt_1ms":474,"lbm_write_time_us":28795,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":452,"mutex_wait_us":104,"peak_mem_usage":51099678,"reinsert_count":0,"spinlock_wait_cycles":13824,"update_count":2050}
I20260812 06:20:17.393074 14782 maintenance_manager.cc:419] P 4deaea3dbb994ef7841ee7e2add4661f: Scheduling FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e): perf score=10.126437
I20260812 06:20:17.430742 14713 maintenance_manager.cc:643] P 4deaea3dbb994ef7841ee7e2add4661f: FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e) complete. Timing: real 0.037s	user 0.014s	sys 0.020s Metrics: {"bytes_written":12307495,"delete_count":0,"lbm_write_time_us":16515,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:17.431197 14782 maintenance_manager.cc:419] P 4deaea3dbb994ef7841ee7e2add4661f: Scheduling FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e): perf score=2.188937
I20260812 06:20:17.443684 14713 maintenance_manager.cc:643] P 4deaea3dbb994ef7841ee7e2add4661f: FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e) complete. Timing: real 0.012s	user 0.003s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4543,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:17.444211 14782 maintenance_manager.cc:419] P 4deaea3dbb994ef7841ee7e2add4661f: Scheduling MajorDeltaCompactionOp(ca29cec422e54676b673d39fc1c23f7e): perf score=1.000000
I20260812 06:20:17.567625 14713 maintenance_manager.cc:643] P 4deaea3dbb994ef7841ee7e2add4661f: MajorDeltaCompactionOp(ca29cec422e54676b673d39fc1c23f7e) complete. Timing: real 0.123s	user 0.102s	sys 0.021s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672282,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":329,"lbm_read_time_us":8658,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23652,"lbm_writes_lt_1ms":443,"mutex_wait_us":66,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":15104,"update_count":2000}
I20260812 06:20:17.568490 14782 maintenance_manager.cc:419] P 4deaea3dbb994ef7841ee7e2add4661f: Scheduling FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e): perf score=10.126437
I20260812 06:20:17.619828 14713 maintenance_manager.cc:643] P 4deaea3dbb994ef7841ee7e2add4661f: FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e) complete. Timing: real 0.051s	user 0.022s	sys 0.017s Metrics: {"bytes_written":12307494,"delete_count":0,"lbm_write_time_us":19107,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:20:17.620389 14782 maintenance_manager.cc:419] P 4deaea3dbb994ef7841ee7e2add4661f: Scheduling FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e): perf score=2.188937
I20260812 06:20:17.630746 14713 maintenance_manager.cc:643] P 4deaea3dbb994ef7841ee7e2add4661f: FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3900,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:17.631348 14782 maintenance_manager.cc:419] P 4deaea3dbb994ef7841ee7e2add4661f: Scheduling MajorDeltaCompactionOp(ca29cec422e54676b673d39fc1c23f7e): perf score=1.000000
I20260812 06:20:17.759274 14713 maintenance_manager.cc:643] P 4deaea3dbb994ef7841ee7e2add4661f: MajorDeltaCompactionOp(ca29cec422e54676b673d39fc1c23f7e) complete. Timing: real 0.128s	user 0.114s	sys 0.012s 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":692,"lbm_read_time_us":7559,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24195,"lbm_writes_lt_1ms":443,"mutex_wait_us":43,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2048,"update_count":2000}
I20260812 06:20:17.759879 14782 maintenance_manager.cc:419] P 4deaea3dbb994ef7841ee7e2add4661f: Scheduling FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e): perf score=10.126437
I20260812 06:20:17.805256 14713 maintenance_manager.cc:643] P 4deaea3dbb994ef7841ee7e2add4661f: FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e) complete. Timing: real 0.045s	user 0.010s	sys 0.034s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18062,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:20:17.805872 14782 maintenance_manager.cc:419] P 4deaea3dbb994ef7841ee7e2add4661f: Scheduling FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e): perf score=2.188937
I20260812 06:20:17.817257 14713 maintenance_manager.cc:643] P 4deaea3dbb994ef7841ee7e2add4661f: FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e) complete. Timing: real 0.011s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4213,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:17.817765 14782 maintenance_manager.cc:419] P 4deaea3dbb994ef7841ee7e2add4661f: Scheduling MajorDeltaCompactionOp(ca29cec422e54676b673d39fc1c23f7e): perf score=1.000000
I20260812 06:20:17.965317 14713 maintenance_manager.cc:643] P 4deaea3dbb994ef7841ee7e2add4661f: MajorDeltaCompactionOp(ca29cec422e54676b673d39fc1c23f7e) complete. Timing: real 0.147s	user 0.099s	sys 0.048s 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":1094,"lbm_read_time_us":11295,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24021,"lbm_writes_lt_1ms":443,"mutex_wait_us":320,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":17920,"update_count":2000}
I20260812 06:20:17.965881 14782 maintenance_manager.cc:419] P 4deaea3dbb994ef7841ee7e2add4661f: Scheduling FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e): perf score=10.126437
I20260812 06:20:18.009702 14713 maintenance_manager.cc:643] P 4deaea3dbb994ef7841ee7e2add4661f: FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e) complete. Timing: real 0.044s	user 0.027s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18571,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:20:18.010183 14782 maintenance_manager.cc:419] P 4deaea3dbb994ef7841ee7e2add4661f: Scheduling FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e): perf score=2.188937
I20260812 06:20:18.021570 14713 maintenance_manager.cc:643] P 4deaea3dbb994ef7841ee7e2add4661f: FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e) complete. Timing: real 0.011s	user 0.001s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4191,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:18.022243 14782 maintenance_manager.cc:419] P 4deaea3dbb994ef7841ee7e2add4661f: Scheduling MajorDeltaCompactionOp(ca29cec422e54676b673d39fc1c23f7e): perf score=1.000000
I20260812 06:20:18.147717 14713 maintenance_manager.cc:643] P 4deaea3dbb994ef7841ee7e2add4661f: MajorDeltaCompactionOp(ca29cec422e54676b673d39fc1c23f7e) complete. Timing: real 0.125s	user 0.104s	sys 0.021s 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":545,"lbm_read_time_us":9405,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24724,"lbm_writes_lt_1ms":443,"mutex_wait_us":288,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9216,"update_count":2000}
I20260812 06:20:18.148417 14782 maintenance_manager.cc:419] P 4deaea3dbb994ef7841ee7e2add4661f: Scheduling FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e): perf score=10.126437
I20260812 06:20:18.196810 14713 maintenance_manager.cc:643] P 4deaea3dbb994ef7841ee7e2add4661f: FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e) complete. Timing: real 0.048s	user 0.023s	sys 0.012s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":16026,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:18.197257 14782 maintenance_manager.cc:419] P 4deaea3dbb994ef7841ee7e2add4661f: Scheduling FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e): perf score=2.188937
I20260812 06:20:18.208738 14713 maintenance_manager.cc:643] P 4deaea3dbb994ef7841ee7e2add4661f: FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e) complete. Timing: real 0.011s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4117,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:18.209444 14782 maintenance_manager.cc:419] P 4deaea3dbb994ef7841ee7e2add4661f: Scheduling FlushMRSOp(ca29cec422e54676b673d39fc1c23f7e): perf score=1.000000
I20260812 06:20:18.237077 14713 maintenance_manager.cc:643] P 4deaea3dbb994ef7841ee7e2add4661f: FlushMRSOp(ca29cec422e54676b673d39fc1c23f7e) complete. Timing: real 0.027s	user 0.025s	sys 0.001s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":76,"dirs.run_cpu_time_us":269,"dirs.run_wall_time_us":1562,"drs_written":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1676,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:20:18.238070 14782 maintenance_manager.cc:419] P 4deaea3dbb994ef7841ee7e2add4661f: Scheduling LogGCOp(ca29cec422e54676b673d39fc1c23f7e): free 120553389 bytes of WAL
I20260812 06:20:18.238361 14713 log_reader.cc:385] T ca29cec422e54676b673d39fc1c23f7e: removed 12 log segments from log reader
I20260812 06:20:18.238436 14713 log.cc:1079] T ca29cec422e54676b673d39fc1c23f7e P 4deaea3dbb994ef7841ee7e2add4661f: Deleting log segment in path: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616361105-14598-0/minicluster-data/ts-0-root/wals/ca29cec422e54676b673d39fc1c23f7e/wal-000000003 (ops 12-16)
I20260812 06:20:18.238479 14713 log.cc:1079] T ca29cec422e54676b673d39fc1c23f7e P 4deaea3dbb994ef7841ee7e2add4661f: Deleting log segment in path: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616361105-14598-0/minicluster-data/ts-0-root/wals/ca29cec422e54676b673d39fc1c23f7e/wal-000000004 (ops 17-21)
I20260812 06:20:18.238508 14713 log.cc:1079] T ca29cec422e54676b673d39fc1c23f7e P 4deaea3dbb994ef7841ee7e2add4661f: Deleting log segment in path: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616361105-14598-0/minicluster-data/ts-0-root/wals/ca29cec422e54676b673d39fc1c23f7e/wal-000000005 (ops 22-26)
I20260812 06:20:18.238538 14713 log.cc:1079] T ca29cec422e54676b673d39fc1c23f7e P 4deaea3dbb994ef7841ee7e2add4661f: Deleting log segment in path: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616361105-14598-0/minicluster-data/ts-0-root/wals/ca29cec422e54676b673d39fc1c23f7e/wal-000000006 (ops 27-31)
I20260812 06:20:18.238574 14713 log.cc:1079] T ca29cec422e54676b673d39fc1c23f7e P 4deaea3dbb994ef7841ee7e2add4661f: Deleting log segment in path: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616361105-14598-0/minicluster-data/ts-0-root/wals/ca29cec422e54676b673d39fc1c23f7e/wal-000000007 (ops 32-36)
I20260812 06:20:18.238608 14713 log.cc:1079] T ca29cec422e54676b673d39fc1c23f7e P 4deaea3dbb994ef7841ee7e2add4661f: Deleting log segment in path: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616361105-14598-0/minicluster-data/ts-0-root/wals/ca29cec422e54676b673d39fc1c23f7e/wal-000000008 (ops 37-41)
I20260812 06:20:18.238638 14713 log.cc:1079] T ca29cec422e54676b673d39fc1c23f7e P 4deaea3dbb994ef7841ee7e2add4661f: Deleting log segment in path: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616361105-14598-0/minicluster-data/ts-0-root/wals/ca29cec422e54676b673d39fc1c23f7e/wal-000000009 (ops 42-46)
I20260812 06:20:18.238664 14713 log.cc:1079] T ca29cec422e54676b673d39fc1c23f7e P 4deaea3dbb994ef7841ee7e2add4661f: Deleting log segment in path: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616361105-14598-0/minicluster-data/ts-0-root/wals/ca29cec422e54676b673d39fc1c23f7e/wal-000000010 (ops 47-50)
I20260812 06:20:18.238693 14713 log.cc:1079] T ca29cec422e54676b673d39fc1c23f7e P 4deaea3dbb994ef7841ee7e2add4661f: Deleting log segment in path: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616361105-14598-0/minicluster-data/ts-0-root/wals/ca29cec422e54676b673d39fc1c23f7e/wal-000000011 (ops 51-55)
I20260812 06:20:18.238726 14713 log.cc:1079] T ca29cec422e54676b673d39fc1c23f7e P 4deaea3dbb994ef7841ee7e2add4661f: Deleting log segment in path: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616361105-14598-0/minicluster-data/ts-0-root/wals/ca29cec422e54676b673d39fc1c23f7e/wal-000000012 (ops 56-60)
I20260812 06:20:18.238759 14713 log.cc:1079] T ca29cec422e54676b673d39fc1c23f7e P 4deaea3dbb994ef7841ee7e2add4661f: Deleting log segment in path: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616361105-14598-0/minicluster-data/ts-0-root/wals/ca29cec422e54676b673d39fc1c23f7e/wal-000000013 (ops 61-64)
I20260812 06:20:18.238790 14713 log.cc:1079] T ca29cec422e54676b673d39fc1c23f7e P 4deaea3dbb994ef7841ee7e2add4661f: Deleting log segment in path: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616361105-14598-0/minicluster-data/ts-0-root/wals/ca29cec422e54676b673d39fc1c23f7e/wal-000000014 (ops 65-69)
I20260812 06:20:18.268446 14713 maintenance_manager.cc:643] P 4deaea3dbb994ef7841ee7e2add4661f: LogGCOp(ca29cec422e54676b673d39fc1c23f7e) complete. Timing: real 0.030s	user 0.000s	sys 0.030s Metrics: {}
I20260812 06:20:18.268903 14782 maintenance_manager.cc:419] P 4deaea3dbb994ef7841ee7e2add4661f: Scheduling FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e): perf score=2.188937
I20260812 06:20:18.288909 14713 maintenance_manager.cc:643] P 4deaea3dbb994ef7841ee7e2add4661f: FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e) complete. Timing: real 0.020s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4677,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:18.289438 14782 maintenance_manager.cc:419] P 4deaea3dbb994ef7841ee7e2add4661f: Scheduling FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e): perf score=2.188937
I20260812 06:20:18.299785 14713 maintenance_manager.cc:643] P 4deaea3dbb994ef7841ee7e2add4661f: FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e) complete. Timing: real 0.010s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102660,"delete_count":0,"lbm_write_time_us":3959,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:18.300319 14782 maintenance_manager.cc:419] P 4deaea3dbb994ef7841ee7e2add4661f: Scheduling MajorDeltaCompactionOp(ca29cec422e54676b673d39fc1c23f7e): perf score=1.000000
I20260812 06:20:18.476855 14713 maintenance_manager.cc:643] P 4deaea3dbb994ef7841ee7e2add4661f: MajorDeltaCompactionOp(ca29cec422e54676b673d39fc1c23f7e) complete. Timing: real 0.176s	user 0.129s	sys 0.045s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877341,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":584,"lbm_read_time_us":11893,"lbm_reads_lt_1ms":674,"lbm_write_time_us":35187,"lbm_writes_lt_1ms":643,"mutex_wait_us":75,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":12416,"thread_start_us":79,"threads_started":1,"update_count":3000}
I20260812 06:20:18.477622 14782 maintenance_manager.cc:419] P 4deaea3dbb994ef7841ee7e2add4661f: Scheduling FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e): perf score=14.095187
I20260812 06:20:18.530284 14713 maintenance_manager.cc:643] P 4deaea3dbb994ef7841ee7e2add4661f: FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e) complete. Timing: real 0.052s	user 0.027s	sys 0.016s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":19326,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:18.530933 14782 maintenance_manager.cc:419] P 4deaea3dbb994ef7841ee7e2add4661f: Scheduling FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e): perf score=2.188937
I20260812 06:20:18.544427 14713 maintenance_manager.cc:643] P 4deaea3dbb994ef7841ee7e2add4661f: FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e) complete. Timing: real 0.013s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4871,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:18.544871 14782 maintenance_manager.cc:419] P 4deaea3dbb994ef7841ee7e2add4661f: Scheduling UndoDeltaBlockGCOp(ca29cec422e54676b673d39fc1c23f7e): 462 bytes on disk
I20260812 06:20:18.545423 14713 maintenance_manager.cc:643] P 4deaea3dbb994ef7841ee7e2add4661f: UndoDeltaBlockGCOp(ca29cec422e54676b673d39fc1c23f7e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":85,"lbm_reads_lt_1ms":4}
I20260812 06:20:18.545958 14782 maintenance_manager.cc:419] P 4deaea3dbb994ef7841ee7e2add4661f: Scheduling MajorDeltaCompactionOp(ca29cec422e54676b673d39fc1c23f7e): perf score=1.000000
I20260812 06:20:18.700155 14713 maintenance_manager.cc:643] P 4deaea3dbb994ef7841ee7e2add4661f: MajorDeltaCompactionOp(ca29cec422e54676b673d39fc1c23f7e) complete. Timing: real 0.154s	user 0.109s	sys 0.044s 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":710,"lbm_read_time_us":10696,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29577,"lbm_writes_lt_1ms":543,"mutex_wait_us":79,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12160,"update_count":2500}
I20260812 06:20:18.705415 14782 maintenance_manager.cc:419] P 4deaea3dbb994ef7841ee7e2add4661f: Scheduling FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e): perf score=12.110812
I20260812 06:20:18.744163 14713 maintenance_manager.cc:643] P 4deaea3dbb994ef7841ee7e2add4661f: FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e) complete. Timing: real 0.038s	user 0.020s	sys 0.015s Metrics: {"bytes_written":13661280,"delete_count":0,"lbm_write_time_us":17234,"lbm_writes_lt_1ms":336,"reinsert_count":0,"update_count":1665}
I20260812 06:20:18.744781 14782 maintenance_manager.cc:419] P 4deaea3dbb994ef7841ee7e2add4661f: Scheduling FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e): perf score=1.196750
I20260812 06:20:18.754928 14713 maintenance_manager.cc:643] P 4deaea3dbb994ef7841ee7e2add4661f: FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":2748830,"delete_count":0,"lbm_write_time_us":3633,"lbm_writes_lt_1ms":70,"reinsert_count":0,"update_count":335}
I20260812 06:20:18.755492 14782 maintenance_manager.cc:419] P 4deaea3dbb994ef7841ee7e2add4661f: Scheduling MajorDeltaCompactionOp(ca29cec422e54676b673d39fc1c23f7e): perf score=1.000000
I20260812 06:20:18.913125 14713 maintenance_manager.cc:643] P 4deaea3dbb994ef7841ee7e2add4661f: MajorDeltaCompactionOp(ca29cec422e54676b673d39fc1c23f7e) complete. Timing: real 0.157s	user 0.104s	sys 0.047s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672238,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":372,"lbm_read_time_us":10186,"lbm_reads_lt_1ms":464,"lbm_write_time_us":27837,"lbm_writes_lt_1ms":443,"mutex_wait_us":54,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:20:18.913920 14782 maintenance_manager.cc:419] P 4deaea3dbb994ef7841ee7e2add4661f: Scheduling FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e): perf score=11.118625
I20260812 06:20:18.956080 14713 maintenance_manager.cc:643] P 4deaea3dbb994ef7841ee7e2add4661f: FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e) complete. Timing: real 0.042s	user 0.024s	sys 0.013s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":18740,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:20:18.956719 14782 maintenance_manager.cc:419] P 4deaea3dbb994ef7841ee7e2add4661f: Scheduling FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e): perf score=2.188937
I20260812 06:20:18.978461 14713 maintenance_manager.cc:643] P 4deaea3dbb994ef7841ee7e2add4661f: FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e) complete. Timing: real 0.022s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4288,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:18.978986 14782 maintenance_manager.cc:419] P 4deaea3dbb994ef7841ee7e2add4661f: Scheduling FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e): perf score=2.188937
I20260812 06:20:19.002315 14713 maintenance_manager.cc:643] P 4deaea3dbb994ef7841ee7e2add4661f: FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e) complete. Timing: real 0.023s	user 0.009s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5861,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:19.003170 14782 maintenance_manager.cc:419] P 4deaea3dbb994ef7841ee7e2add4661f: Scheduling MajorDeltaCompactionOp(ca29cec422e54676b673d39fc1c23f7e): perf score=1.000000
I20260812 06:20:19.183256 14713 maintenance_manager.cc:643] P 4deaea3dbb994ef7841ee7e2add4661f: MajorDeltaCompactionOp(ca29cec422e54676b673d39fc1c23f7e) complete. Timing: real 0.180s	user 0.127s	sys 0.049s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774799,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":735,"lbm_read_time_us":13631,"lbm_reads_lt_1ms":573,"lbm_write_time_us":30910,"lbm_writes_lt_1ms":543,"mutex_wait_us":314,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11008,"update_count":2500}
I20260812 06:20:19.183995 14782 maintenance_manager.cc:419] P 4deaea3dbb994ef7841ee7e2add4661f: Scheduling FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e): perf score=11.118625
I20260812 06:20:19.217669 14713 maintenance_manager.cc:643] P 4deaea3dbb994ef7841ee7e2add4661f: FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e) complete. Timing: real 0.033s	user 0.025s	sys 0.007s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":13801,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:19.218348 14782 maintenance_manager.cc:419] P 4deaea3dbb994ef7841ee7e2add4661f: Scheduling FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e): perf score=2.188937
I20260812 06:20:19.242419 14713 maintenance_manager.cc:643] P 4deaea3dbb994ef7841ee7e2add4661f: FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e) complete. Timing: real 0.024s	user 0.012s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5299,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:19.242942 14782 maintenance_manager.cc:419] P 4deaea3dbb994ef7841ee7e2add4661f: Scheduling FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e): perf score=2.188937
I20260812 06:20:19.254051 14713 maintenance_manager.cc:643] P 4deaea3dbb994ef7841ee7e2add4661f: FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3961,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:19.254638 14782 maintenance_manager.cc:419] P 4deaea3dbb994ef7841ee7e2add4661f: Scheduling MajorDeltaCompactionOp(ca29cec422e54676b673d39fc1c23f7e): perf score=1.000000
I20260812 06:20:19.436745 14713 maintenance_manager.cc:643] P 4deaea3dbb994ef7841ee7e2add4661f: MajorDeltaCompactionOp(ca29cec422e54676b673d39fc1c23f7e) complete. Timing: real 0.182s	user 0.119s	sys 0.051s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774799,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":875,"lbm_read_time_us":10715,"lbm_reads_lt_1ms":573,"lbm_write_time_us":29535,"lbm_writes_lt_1ms":543,"mutex_wait_us":314,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:20:19.437397 14782 maintenance_manager.cc:419] P 4deaea3dbb994ef7841ee7e2add4661f: Scheduling FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e): perf score=11.118625
I20260812 06:20:19.492602 14713 maintenance_manager.cc:643] P 4deaea3dbb994ef7841ee7e2add4661f: FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e) complete. Timing: real 0.055s	user 0.025s	sys 0.012s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":17408,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:19.493119 14782 maintenance_manager.cc:419] P 4deaea3dbb994ef7841ee7e2add4661f: Scheduling FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e): perf score=2.188937
I20260812 06:20:19.511849 14713 maintenance_manager.cc:643] P 4deaea3dbb994ef7841ee7e2add4661f: FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e) complete. Timing: real 0.019s	user 0.011s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6387,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:19.512354 14782 maintenance_manager.cc:419] P 4deaea3dbb994ef7841ee7e2add4661f: Scheduling FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e): perf score=2.188937
I20260812 06:20:19.522078 14713 maintenance_manager.cc:643] P 4deaea3dbb994ef7841ee7e2add4661f: FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3484,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:19.522544 14782 maintenance_manager.cc:419] P 4deaea3dbb994ef7841ee7e2add4661f: Scheduling MajorDeltaCompactionOp(ca29cec422e54676b673d39fc1c23f7e): perf score=1.000000
I20260812 06:20:19.685423 14713 maintenance_manager.cc:643] P 4deaea3dbb994ef7841ee7e2add4661f: MajorDeltaCompactionOp(ca29cec422e54676b673d39fc1c23f7e) complete. Timing: real 0.163s	user 0.120s	sys 0.033s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774801,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":276,"lbm_read_time_us":12248,"lbm_reads_lt_1ms":573,"lbm_write_time_us":31363,"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:20:19.686147 14782 maintenance_manager.cc:419] P 4deaea3dbb994ef7841ee7e2add4661f: Scheduling FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e): perf score=11.118625
I20260812 06:20:19.717980 14713 maintenance_manager.cc:643] P 4deaea3dbb994ef7841ee7e2add4661f: FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e) complete. Timing: real 0.032s	user 0.030s	sys 0.000s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":13849,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:19.718714 14782 maintenance_manager.cc:419] P 4deaea3dbb994ef7841ee7e2add4661f: Scheduling FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e): perf score=2.188937
I20260812 06:20:19.745891 14713 maintenance_manager.cc:643] P 4deaea3dbb994ef7841ee7e2add4661f: FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e) complete. Timing: real 0.027s	user 0.014s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5580,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:19.746762 14782 maintenance_manager.cc:419] P 4deaea3dbb994ef7841ee7e2add4661f: Scheduling FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e): perf score=2.188937
I20260812 06:20:19.759296 14713 maintenance_manager.cc:643] P 4deaea3dbb994ef7841ee7e2add4661f: FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e) complete. Timing: real 0.012s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4749,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:19.759793 14782 maintenance_manager.cc:419] P 4deaea3dbb994ef7841ee7e2add4661f: Scheduling FlushMRSOp(ca29cec422e54676b673d39fc1c23f7e): perf score=1.000000
I20260812 06:20:19.795413 14713 maintenance_manager.cc:643] P 4deaea3dbb994ef7841ee7e2add4661f: FlushMRSOp(ca29cec422e54676b673d39fc1c23f7e) complete. Timing: real 0.035s	user 0.028s	sys 0.004s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":75,"dirs.run_cpu_time_us":201,"dirs.run_wall_time_us":1470,"drs_written":1,"lbm_read_time_us":66,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2424,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:20:19.796365 14782 maintenance_manager.cc:419] P 4deaea3dbb994ef7841ee7e2add4661f: Scheduling LogGCOp(ca29cec422e54676b673d39fc1c23f7e): free 124257255 bytes of WAL
I20260812 06:20:19.796653 14713 log_reader.cc:385] T ca29cec422e54676b673d39fc1c23f7e: removed 12 log segments from log reader
I20260812 06:20:19.796730 14713 log.cc:1079] T ca29cec422e54676b673d39fc1c23f7e P 4deaea3dbb994ef7841ee7e2add4661f: Deleting log segment in path: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616361105-14598-0/minicluster-data/ts-0-root/wals/ca29cec422e54676b673d39fc1c23f7e/wal-000000015 (ops 70-74)
I20260812 06:20:19.796833 14713 log.cc:1079] T ca29cec422e54676b673d39fc1c23f7e P 4deaea3dbb994ef7841ee7e2add4661f: Deleting log segment in path: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616361105-14598-0/minicluster-data/ts-0-root/wals/ca29cec422e54676b673d39fc1c23f7e/wal-000000016 (ops 75-79)
I20260812 06:20:19.796880 14713 log.cc:1079] T ca29cec422e54676b673d39fc1c23f7e P 4deaea3dbb994ef7841ee7e2add4661f: Deleting log segment in path: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616361105-14598-0/minicluster-data/ts-0-root/wals/ca29cec422e54676b673d39fc1c23f7e/wal-000000017 (ops 80-84)
I20260812 06:20:19.796928 14713 log.cc:1079] T ca29cec422e54676b673d39fc1c23f7e P 4deaea3dbb994ef7841ee7e2add4661f: Deleting log segment in path: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616361105-14598-0/minicluster-data/ts-0-root/wals/ca29cec422e54676b673d39fc1c23f7e/wal-000000018 (ops 85-89)
I20260812 06:20:19.796980 14713 log.cc:1079] T ca29cec422e54676b673d39fc1c23f7e P 4deaea3dbb994ef7841ee7e2add4661f: Deleting log segment in path: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616361105-14598-0/minicluster-data/ts-0-root/wals/ca29cec422e54676b673d39fc1c23f7e/wal-000000019 (ops 90-94)
I20260812 06:20:19.797026 14713 log.cc:1079] T ca29cec422e54676b673d39fc1c23f7e P 4deaea3dbb994ef7841ee7e2add4661f: Deleting log segment in path: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616361105-14598-0/minicluster-data/ts-0-root/wals/ca29cec422e54676b673d39fc1c23f7e/wal-000000020 (ops 95-99)
I20260812 06:20:19.797075 14713 log.cc:1079] T ca29cec422e54676b673d39fc1c23f7e P 4deaea3dbb994ef7841ee7e2add4661f: Deleting log segment in path: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616361105-14598-0/minicluster-data/ts-0-root/wals/ca29cec422e54676b673d39fc1c23f7e/wal-000000021 (ops 100-104)
I20260812 06:20:19.797118 14713 log.cc:1079] T ca29cec422e54676b673d39fc1c23f7e P 4deaea3dbb994ef7841ee7e2add4661f: Deleting log segment in path: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616361105-14598-0/minicluster-data/ts-0-root/wals/ca29cec422e54676b673d39fc1c23f7e/wal-000000022 (ops 105-109)
I20260812 06:20:19.797163 14713 log.cc:1079] T ca29cec422e54676b673d39fc1c23f7e P 4deaea3dbb994ef7841ee7e2add4661f: Deleting log segment in path: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616361105-14598-0/minicluster-data/ts-0-root/wals/ca29cec422e54676b673d39fc1c23f7e/wal-000000023 (ops 110-114)
I20260812 06:20:19.797205 14713 log.cc:1079] T ca29cec422e54676b673d39fc1c23f7e P 4deaea3dbb994ef7841ee7e2add4661f: Deleting log segment in path: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616361105-14598-0/minicluster-data/ts-0-root/wals/ca29cec422e54676b673d39fc1c23f7e/wal-000000024 (ops 115-119)
I20260812 06:20:19.797245 14713 log.cc:1079] T ca29cec422e54676b673d39fc1c23f7e P 4deaea3dbb994ef7841ee7e2add4661f: Deleting log segment in path: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616361105-14598-0/minicluster-data/ts-0-root/wals/ca29cec422e54676b673d39fc1c23f7e/wal-000000025 (ops 120-124)
I20260812 06:20:19.797291 14713 log.cc:1079] T ca29cec422e54676b673d39fc1c23f7e P 4deaea3dbb994ef7841ee7e2add4661f: Deleting log segment in path: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616361105-14598-0/minicluster-data/ts-0-root/wals/ca29cec422e54676b673d39fc1c23f7e/wal-000000026 (ops 125-128)
I20260812 06:20:19.824002 14713 maintenance_manager.cc:643] P 4deaea3dbb994ef7841ee7e2add4661f: LogGCOp(ca29cec422e54676b673d39fc1c23f7e) complete. Timing: real 0.027s	user 0.000s	sys 0.024s Metrics: {}
I20260812 06:20:19.824489 14782 maintenance_manager.cc:419] P 4deaea3dbb994ef7841ee7e2add4661f: Scheduling UndoDeltaBlockGCOp(ca29cec422e54676b673d39fc1c23f7e): 483 bytes on disk
I20260812 06:20:19.825006 14713 maintenance_manager.cc:643] P 4deaea3dbb994ef7841ee7e2add4661f: UndoDeltaBlockGCOp(ca29cec422e54676b673d39fc1c23f7e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":64,"lbm_reads_lt_1ms":4}
I20260812 06:20:19.825529 14782 maintenance_manager.cc:419] P 4deaea3dbb994ef7841ee7e2add4661f: Scheduling FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e): perf score=3.181125
I20260812 06:20:19.846437 14713 maintenance_manager.cc:643] P 4deaea3dbb994ef7841ee7e2add4661f: FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e) complete. Timing: real 0.021s	user 0.008s	sys 0.005s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4755,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:19.847054 14782 maintenance_manager.cc:419] P 4deaea3dbb994ef7841ee7e2add4661f: Scheduling FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e): perf score=2.188937
I20260812 06:20:19.857860 14713 maintenance_manager.cc:643] P 4deaea3dbb994ef7841ee7e2add4661f: FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3840,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:19.858429 14782 maintenance_manager.cc:419] P 4deaea3dbb994ef7841ee7e2add4661f: Scheduling MajorDeltaCompactionOp(ca29cec422e54676b673d39fc1c23f7e): perf score=1.000000
I20260812 06:20:20.092484 14713 maintenance_manager.cc:643] P 4deaea3dbb994ef7841ee7e2add4661f: MajorDeltaCompactionOp(ca29cec422e54676b673d39fc1c23f7e) complete. Timing: real 0.232s	user 0.166s	sys 0.064s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32979847,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":620,"lbm_read_time_us":17200,"lbm_reads_lt_1ms":775,"lbm_write_time_us":37539,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":4096,"thread_start_us":128,"threads_started":1,"update_count":3500}
I20260812 06:20:20.093161 14782 maintenance_manager.cc:419] P 4deaea3dbb994ef7841ee7e2add4661f: Scheduling FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e): perf score=16.079562
I20260812 06:20:20.168793 14713 maintenance_manager.cc:643] P 4deaea3dbb994ef7841ee7e2add4661f: FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e) complete. Timing: real 0.075s	user 0.036s	sys 0.028s Metrics: {"bytes_written":17681652,"delete_count":0,"lbm_write_time_us":28870,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":433,"reinsert_count":0,"update_count":2155}
I20260812 06:20:20.169288 14782 maintenance_manager.cc:419] P 4deaea3dbb994ef7841ee7e2add4661f: Scheduling FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e): perf score=5.165500
I20260812 06:20:20.187153 14713 maintenance_manager.cc:643] P 4deaea3dbb994ef7841ee7e2add4661f: FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e) complete. Timing: real 0.018s	user 0.012s	sys 0.004s Metrics: {"bytes_written":6933334,"delete_count":0,"lbm_write_time_us":7319,"lbm_writes_lt_1ms":172,"reinsert_count":0,"update_count":845}
I20260812 06:20:20.187645 14782 maintenance_manager.cc:419] P 4deaea3dbb994ef7841ee7e2add4661f: Scheduling MajorDeltaCompactionOp(ca29cec422e54676b673d39fc1c23f7e): perf score=1.000000
I20260812 06:20:20.400224 14713 maintenance_manager.cc:643] P 4deaea3dbb994ef7841ee7e2add4661f: MajorDeltaCompactionOp(ca29cec422e54676b673d39fc1c23f7e) complete. Timing: real 0.212s	user 0.126s	sys 0.073s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877108,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":831,"lbm_read_time_us":12321,"lbm_reads_lt_1ms":672,"lbm_write_time_us":37440,"lbm_writes_lt_1ms":643,"mutex_wait_us":384,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":3000}
I20260812 06:20:20.400959 14782 maintenance_manager.cc:419] P 4deaea3dbb994ef7841ee7e2add4661f: Scheduling FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e): perf score=18.063937
I20260812 06:20:20.482450 14713 maintenance_manager.cc:643] P 4deaea3dbb994ef7841ee7e2add4661f: FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e) complete. Timing: real 0.081s	user 0.043s	sys 0.024s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":31114,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:20.483104 14782 maintenance_manager.cc:419] P 4deaea3dbb994ef7841ee7e2add4661f: Scheduling FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e): perf score=2.188937
I20260812 06:20:20.500000 14713 maintenance_manager.cc:643] P 4deaea3dbb994ef7841ee7e2add4661f: FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e) complete. Timing: real 0.017s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6231,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:20.500798 14782 maintenance_manager.cc:419] P 4deaea3dbb994ef7841ee7e2add4661f: Scheduling MajorDeltaCompactionOp(ca29cec422e54676b673d39fc1c23f7e): perf score=1.000000
I20260812 06:20:20.699373 14713 maintenance_manager.cc:643] P 4deaea3dbb994ef7841ee7e2add4661f: MajorDeltaCompactionOp(ca29cec422e54676b673d39fc1c23f7e) complete. Timing: real 0.198s	user 0.121s	sys 0.077s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877104,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1101,"lbm_read_time_us":13883,"lbm_reads_lt_1ms":672,"lbm_write_time_us":35695,"lbm_writes_lt_1ms":643,"mutex_wait_us":325,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":11648,"update_count":3000}
I20260812 06:20:20.700222 14782 maintenance_manager.cc:419] P 4deaea3dbb994ef7841ee7e2add4661f: Scheduling FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e): perf score=14.095187
I20260812 06:20:20.761030 14713 maintenance_manager.cc:643] P 4deaea3dbb994ef7841ee7e2add4661f: FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e) complete. Timing: real 0.061s	user 0.033s	sys 0.017s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":21923,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:20.761688 14782 maintenance_manager.cc:419] P 4deaea3dbb994ef7841ee7e2add4661f: Scheduling FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e): perf score=2.188937
I20260812 06:20:20.774480 14713 maintenance_manager.cc:643] P 4deaea3dbb994ef7841ee7e2add4661f: FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e) complete. Timing: real 0.013s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4503,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:20.774994 14782 maintenance_manager.cc:419] P 4deaea3dbb994ef7841ee7e2add4661f: Scheduling MajorDeltaCompactionOp(ca29cec422e54676b673d39fc1c23f7e): perf score=1.000000
I20260812 06:20:20.942256 14713 maintenance_manager.cc:643] P 4deaea3dbb994ef7841ee7e2add4661f: MajorDeltaCompactionOp(ca29cec422e54676b673d39fc1c23f7e) complete. Timing: real 0.167s	user 0.117s	sys 0.047s 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":128,"lbm_read_time_us":11067,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30036,"lbm_writes_lt_1ms":543,"mutex_wait_us":20,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":15616,"update_count":2500}
I20260812 06:20:20.942934 14782 maintenance_manager.cc:419] P 4deaea3dbb994ef7841ee7e2add4661f: Scheduling FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e): perf score=14.095187
I20260812 06:20:21.000654 14713 maintenance_manager.cc:643] P 4deaea3dbb994ef7841ee7e2add4661f: FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e) complete. Timing: real 0.057s	user 0.030s	sys 0.027s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":26522,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:20:21.001292 14782 maintenance_manager.cc:419] P 4deaea3dbb994ef7841ee7e2add4661f: Scheduling FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e): perf score=2.188937
I20260812 06:20:21.018859 14713 maintenance_manager.cc:643] P 4deaea3dbb994ef7841ee7e2add4661f: FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e) complete. Timing: real 0.017s	user 0.015s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6951,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:21.019645 14782 maintenance_manager.cc:419] P 4deaea3dbb994ef7841ee7e2add4661f: Scheduling MajorDeltaCompactionOp(ca29cec422e54676b673d39fc1c23f7e): perf score=1.000000
I20260812 06:20:21.196599 14713 maintenance_manager.cc:643] P 4deaea3dbb994ef7841ee7e2add4661f: MajorDeltaCompactionOp(ca29cec422e54676b673d39fc1c23f7e) complete. Timing: real 0.177s	user 0.141s	sys 0.028s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":453,"lbm_read_time_us":11725,"lbm_reads_lt_1ms":564,"lbm_write_time_us":31777,"lbm_writes_lt_1ms":543,"mutex_wait_us":90,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2560,"update_count":2500}
I20260812 06:20:21.197350 14782 maintenance_manager.cc:419] P 4deaea3dbb994ef7841ee7e2add4661f: Scheduling FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e): perf score=14.095187
I20260812 06:20:21.261121 14713 maintenance_manager.cc:643] P 4deaea3dbb994ef7841ee7e2add4661f: FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e) complete. Timing: real 0.064s	user 0.032s	sys 0.024s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22080,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:21.261711 14782 maintenance_manager.cc:419] P 4deaea3dbb994ef7841ee7e2add4661f: Scheduling FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e): perf score=2.188937
I20260812 06:20:21.273046 14713 maintenance_manager.cc:643] P 4deaea3dbb994ef7841ee7e2add4661f: FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e) complete. Timing: real 0.011s	user 0.001s	sys 0.009s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4496,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:21.273608 14782 maintenance_manager.cc:419] P 4deaea3dbb994ef7841ee7e2add4661f: Scheduling FlushMRSOp(ca29cec422e54676b673d39fc1c23f7e): perf score=1.000000
I20260812 06:20:21.316442 14713 maintenance_manager.cc:643] P 4deaea3dbb994ef7841ee7e2add4661f: FlushMRSOp(ca29cec422e54676b673d39fc1c23f7e) complete. Timing: real 0.043s	user 0.024s	sys 0.005s Metrics: {"bytes_written":1193507,"cfile_init":1,"dirs.queue_time_us":103,"dirs.run_cpu_time_us":248,"dirs.run_wall_time_us":1725,"drs_written":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2356,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:20:21.317279 14782 maintenance_manager.cc:419] P 4deaea3dbb994ef7841ee7e2add4661f: Scheduling LogGCOp(ca29cec422e54676b673d39fc1c23f7e): free 121006648 bytes of WAL
I20260812 06:20:21.317562 14713 log_reader.cc:385] T ca29cec422e54676b673d39fc1c23f7e: removed 12 log segments from log reader
I20260812 06:20:21.317629 14713 log.cc:1079] T ca29cec422e54676b673d39fc1c23f7e P 4deaea3dbb994ef7841ee7e2add4661f: Deleting log segment in path: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616361105-14598-0/minicluster-data/ts-0-root/wals/ca29cec422e54676b673d39fc1c23f7e/wal-000000027 (ops 129-133)
I20260812 06:20:21.317679 14713 log.cc:1079] T ca29cec422e54676b673d39fc1c23f7e P 4deaea3dbb994ef7841ee7e2add4661f: Deleting log segment in path: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616361105-14598-0/minicluster-data/ts-0-root/wals/ca29cec422e54676b673d39fc1c23f7e/wal-000000028 (ops 134-138)
I20260812 06:20:21.317731 14713 log.cc:1079] T ca29cec422e54676b673d39fc1c23f7e P 4deaea3dbb994ef7841ee7e2add4661f: Deleting log segment in path: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616361105-14598-0/minicluster-data/ts-0-root/wals/ca29cec422e54676b673d39fc1c23f7e/wal-000000029 (ops 139-143)
I20260812 06:20:21.317775 14713 log.cc:1079] T ca29cec422e54676b673d39fc1c23f7e P 4deaea3dbb994ef7841ee7e2add4661f: Deleting log segment in path: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616361105-14598-0/minicluster-data/ts-0-root/wals/ca29cec422e54676b673d39fc1c23f7e/wal-000000030 (ops 144-148)
I20260812 06:20:21.317808 14713 log.cc:1079] T ca29cec422e54676b673d39fc1c23f7e P 4deaea3dbb994ef7841ee7e2add4661f: Deleting log segment in path: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616361105-14598-0/minicluster-data/ts-0-root/wals/ca29cec422e54676b673d39fc1c23f7e/wal-000000031 (ops 149-153)
I20260812 06:20:21.317842 14713 log.cc:1079] T ca29cec422e54676b673d39fc1c23f7e P 4deaea3dbb994ef7841ee7e2add4661f: Deleting log segment in path: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616361105-14598-0/minicluster-data/ts-0-root/wals/ca29cec422e54676b673d39fc1c23f7e/wal-000000032 (ops 154-158)
I20260812 06:20:21.317878 14713 log.cc:1079] T ca29cec422e54676b673d39fc1c23f7e P 4deaea3dbb994ef7841ee7e2add4661f: Deleting log segment in path: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616361105-14598-0/minicluster-data/ts-0-root/wals/ca29cec422e54676b673d39fc1c23f7e/wal-000000033 (ops 159-163)
I20260812 06:20:21.317917 14713 log.cc:1079] T ca29cec422e54676b673d39fc1c23f7e P 4deaea3dbb994ef7841ee7e2add4661f: Deleting log segment in path: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616361105-14598-0/minicluster-data/ts-0-root/wals/ca29cec422e54676b673d39fc1c23f7e/wal-000000034 (ops 164-168)
I20260812 06:20:21.317956 14713 log.cc:1079] T ca29cec422e54676b673d39fc1c23f7e P 4deaea3dbb994ef7841ee7e2add4661f: Deleting log segment in path: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616361105-14598-0/minicluster-data/ts-0-root/wals/ca29cec422e54676b673d39fc1c23f7e/wal-000000035 (ops 169-173)
I20260812 06:20:21.317996 14713 log.cc:1079] T ca29cec422e54676b673d39fc1c23f7e P 4deaea3dbb994ef7841ee7e2add4661f: Deleting log segment in path: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616361105-14598-0/minicluster-data/ts-0-root/wals/ca29cec422e54676b673d39fc1c23f7e/wal-000000036 (ops 174-178)
I20260812 06:20:21.318033 14713 log.cc:1079] T ca29cec422e54676b673d39fc1c23f7e P 4deaea3dbb994ef7841ee7e2add4661f: Deleting log segment in path: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616361105-14598-0/minicluster-data/ts-0-root/wals/ca29cec422e54676b673d39fc1c23f7e/wal-000000037 (ops 179-182)
I20260812 06:20:21.318071 14713 log.cc:1079] T ca29cec422e54676b673d39fc1c23f7e P 4deaea3dbb994ef7841ee7e2add4661f: Deleting log segment in path: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515616361105-14598-0/minicluster-data/ts-0-root/wals/ca29cec422e54676b673d39fc1c23f7e/wal-000000038 (ops 183-187)
I20260812 06:20:21.343384 14713 maintenance_manager.cc:643] P 4deaea3dbb994ef7841ee7e2add4661f: LogGCOp(ca29cec422e54676b673d39fc1c23f7e) complete. Timing: real 0.026s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:20:21.343796 14782 maintenance_manager.cc:419] P 4deaea3dbb994ef7841ee7e2add4661f: Scheduling UndoDeltaBlockGCOp(ca29cec422e54676b673d39fc1c23f7e): 462 bytes on disk
I20260812 06:20:21.344318 14713 maintenance_manager.cc:643] P 4deaea3dbb994ef7841ee7e2add4661f: UndoDeltaBlockGCOp(ca29cec422e54676b673d39fc1c23f7e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4}
I20260812 06:20:21.344928 14782 maintenance_manager.cc:419] P 4deaea3dbb994ef7841ee7e2add4661f: Scheduling FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e): perf score=2.188937
I20260812 06:20:21.367317 14713 maintenance_manager.cc:643] P 4deaea3dbb994ef7841ee7e2add4661f: FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e) complete. Timing: real 0.022s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6251,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:21.367774 14782 maintenance_manager.cc:419] P 4deaea3dbb994ef7841ee7e2add4661f: Scheduling FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e): perf score=2.188937
I20260812 06:20:21.378194 14713 maintenance_manager.cc:643] P 4deaea3dbb994ef7841ee7e2add4661f: FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e) complete. Timing: real 0.010s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3957,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:21.378662 14782 maintenance_manager.cc:419] P 4deaea3dbb994ef7841ee7e2add4661f: Scheduling MajorDeltaCompactionOp(ca29cec422e54676b673d39fc1c23f7e): perf score=1.000000
I20260812 06:20:21.601745 14713 maintenance_manager.cc:643] P 4deaea3dbb994ef7841ee7e2add4661f: MajorDeltaCompactionOp(ca29cec422e54676b673d39fc1c23f7e) complete. Timing: real 0.223s	user 0.161s	sys 0.052s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979750,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":529,"lbm_read_time_us":16135,"lbm_reads_lt_1ms":774,"lbm_write_time_us":37231,"lbm_writes_lt_1ms":743,"mutex_wait_us":22,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":2048,"thread_start_us":78,"threads_started":1,"update_count":3500}
I20260812 06:20:21.602442 14782 maintenance_manager.cc:419] P 4deaea3dbb994ef7841ee7e2add4661f: Scheduling FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e): perf score=15.087375
I20260812 06:20:21.619977 14598 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.962s	user 1.853s	sys 0.141s
I20260812 06:20:21.648392 14713 maintenance_manager.cc:643] P 4deaea3dbb994ef7841ee7e2add4661f: FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e) complete. Timing: real 0.046s	user 0.016s	sys 0.029s Metrics: {"bytes_written":16902197,"delete_count":0,"lbm_write_time_us":21647,"lbm_writes_lt_1ms":415,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2060}
I20260812 06:20:21.648882 14782 maintenance_manager.cc:419] P 4deaea3dbb994ef7841ee7e2add4661f: Scheduling FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e): perf score=2.188937
I20260812 06:20:21.662120 14713 maintenance_manager.cc:643] P 4deaea3dbb994ef7841ee7e2add4661f: FlushDeltaMemStoresOp(ca29cec422e54676b673d39fc1c23f7e) complete. Timing: real 0.013s	user 0.009s	sys 0.002s Metrics: {"bytes_written":3610355,"delete_count":0,"lbm_write_time_us":4616,"lbm_writes_lt_1ms":91,"reinsert_count":0,"update_count":440}
I20260812 06:20:21.662822 14782 maintenance_manager.cc:419] P 4deaea3dbb994ef7841ee7e2add4661f: Scheduling MajorDeltaCompactionOp(ca29cec422e54676b673d39fc1c23f7e): perf score=1.000000
I20260812 06:20:21.665673 14598 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.045s	user 0.003s	sys 0.000s
I20260812 06:20:21.666417 14598 tablet_server.cc:179] TabletServer@127.14.65.129:0 shutting down...
I20260812 06:20:21.807474 14713 maintenance_manager.cc:643] P 4deaea3dbb994ef7841ee7e2add4661f: MajorDeltaCompactionOp(ca29cec422e54676b673d39fc1c23f7e) complete. Timing: real 0.144s	user 0.111s	sys 0.031s Metrics: {"cfile_cache_hit":30,"cfile_cache_hit_bytes":4262390,"cfile_cache_miss":502,"cfile_cache_miss_bytes":20512290,"cfile_init":4,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":379,"lbm_read_time_us":8334,"lbm_reads_lt_1ms":518,"lbm_write_time_us":26633,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:20:21.808765 14598 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:21.809166 14598 tablet_replica.cc:333] T ca29cec422e54676b673d39fc1c23f7e P 4deaea3dbb994ef7841ee7e2add4661f: stopping tablet replica
I20260812 06:20:21.809442 14598 raft_consensus.cc:2243] T ca29cec422e54676b673d39fc1c23f7e P 4deaea3dbb994ef7841ee7e2add4661f [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:21.809731 14598 raft_consensus.cc:2272] T ca29cec422e54676b673d39fc1c23f7e P 4deaea3dbb994ef7841ee7e2add4661f [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:21.825598 14598 tablet_server.cc:196] TabletServer@127.14.65.129:0 shutdown complete.
I20260812 06:20:21.855479 14598 master.cc:562] Master@127.14.65.190:34681 shutting down...
I20260812 06:20:21.859372 14598 raft_consensus.cc:2243] T 00000000000000000000000000000000 P c8c45ebc7f60401da9cf49d208a628d7 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:21.859580 14598 raft_consensus.cc:2272] T 00000000000000000000000000000000 P c8c45ebc7f60401da9cf49d208a628d7 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:21.859676 14598 tablet_replica.cc:333] T 00000000000000000000000000000000 P c8c45ebc7f60401da9cf49d208a628d7: stopping tablet replica
I20260812 06:20:21.872218 14598 master.cc:584] Master@127.14.65.190:34681 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5590 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:20:21.974761 14598 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.14.65.190:39799
I20260812 06:20:21.975212 14598 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:21.977707 14812 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:20:21.977717 14813 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:21.977917 14815 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:20:21.977957 14598 server_base.cc:1061] running on GCE node
I20260812 06:20:21.978163 14598 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:21.978233 14598 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:20:21.978259 14598 hybrid_clock.cc:648] HybridClock initialized: now 1786515621978259 us; error 0 us; skew 500 ppm
I20260812 06:20:21.979172 14598 webserver.cc:533] Webserver started at http://127.14.65.190:37973/ using document root <none> and password file <none>
I20260812 06:20:21.979415 14598 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:21.979502 14598 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:21.979598 14598 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:21.980052 14598 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616361105-14598-0/minicluster-data/master-0-root/instance:
uuid: "580a560ffed849d89f3b09aba3eb0ef4"
format_stamp: "Formatted at 2026-08-12 06:20:21 on dist-test-slave-8w9v"
I20260812 06:20:21.981772 14598 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:21.982842 14820 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:20:21.983086 14598 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:21.983180 14598 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616361105-14598-0/minicluster-data/master-0-root
uuid: "580a560ffed849d89f3b09aba3eb0ef4"
format_stamp: "Formatted at 2026-08-12 06:20:21 on dist-test-slave-8w9v"
I20260812 06:20:21.983274 14598 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616361105-14598-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616361105-14598-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616361105-14598-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:20:21.997386 14598 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:21.997805 14598 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:22.002485 14598 rpc_server.cc:307] RPC server started. Bound to: 127.14.65.190:39799
I20260812 06:20:22.002594 14883 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.14.65.190:39799 every 8 connection(s)
I20260812 06:20:22.005169 14884 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:20:22.006985 14884 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 580a560ffed849d89f3b09aba3eb0ef4: Bootstrap starting.
I20260812 06:20:22.007742 14884 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 580a560ffed849d89f3b09aba3eb0ef4: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:22.008751 14884 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 580a560ffed849d89f3b09aba3eb0ef4: No bootstrap required, opened a new log
I20260812 06:20:22.009106 14884 raft_consensus.cc:359] T 00000000000000000000000000000000 P 580a560ffed849d89f3b09aba3eb0ef4 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "580a560ffed849d89f3b09aba3eb0ef4" member_type: VOTER }
I20260812 06:20:22.009191 14884 raft_consensus.cc:385] T 00000000000000000000000000000000 P 580a560ffed849d89f3b09aba3eb0ef4 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:22.009213 14884 raft_consensus.cc:740] T 00000000000000000000000000000000 P 580a560ffed849d89f3b09aba3eb0ef4 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 580a560ffed849d89f3b09aba3eb0ef4, State: Initialized, Role: FOLLOWER
I20260812 06:20:22.009320 14884 consensus_queue.cc:260] T 00000000000000000000000000000000 P 580a560ffed849d89f3b09aba3eb0ef4 [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: "580a560ffed849d89f3b09aba3eb0ef4" member_type: VOTER }
I20260812 06:20:22.009409 14884 raft_consensus.cc:399] T 00000000000000000000000000000000 P 580a560ffed849d89f3b09aba3eb0ef4 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:22.009442 14884 raft_consensus.cc:493] T 00000000000000000000000000000000 P 580a560ffed849d89f3b09aba3eb0ef4 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:22.009477 14884 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 580a560ffed849d89f3b09aba3eb0ef4 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:22.010113 14884 raft_consensus.cc:515] T 00000000000000000000000000000000 P 580a560ffed849d89f3b09aba3eb0ef4 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "580a560ffed849d89f3b09aba3eb0ef4" member_type: VOTER }
I20260812 06:20:22.010224 14884 leader_election.cc:304] T 00000000000000000000000000000000 P 580a560ffed849d89f3b09aba3eb0ef4 [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: 580a560ffed849d89f3b09aba3eb0ef4; no voters: 
I20260812 06:20:22.010363 14884 leader_election.cc:290] T 00000000000000000000000000000000 P 580a560ffed849d89f3b09aba3eb0ef4 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:22.010500 14887 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 580a560ffed849d89f3b09aba3eb0ef4 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:22.010721 14887 raft_consensus.cc:697] T 00000000000000000000000000000000 P 580a560ffed849d89f3b09aba3eb0ef4 [term 1 LEADER]: Becoming Leader. State: Replica: 580a560ffed849d89f3b09aba3eb0ef4, State: Running, Role: LEADER
I20260812 06:20:22.010901 14884 sys_catalog.cc:565] T 00000000000000000000000000000000 P 580a560ffed849d89f3b09aba3eb0ef4 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:22.010878 14887 consensus_queue.cc:237] T 00000000000000000000000000000000 P 580a560ffed849d89f3b09aba3eb0ef4 [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: "580a560ffed849d89f3b09aba3eb0ef4" member_type: VOTER }
I20260812 06:20:22.011369 14889 sys_catalog.cc:455] T 00000000000000000000000000000000 P 580a560ffed849d89f3b09aba3eb0ef4 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "580a560ffed849d89f3b09aba3eb0ef4" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "580a560ffed849d89f3b09aba3eb0ef4" member_type: VOTER } }
I20260812 06:20:22.011399 14890 sys_catalog.cc:455] T 00000000000000000000000000000000 P 580a560ffed849d89f3b09aba3eb0ef4 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 580a560ffed849d89f3b09aba3eb0ef4. Latest consensus state: current_term: 1 leader_uuid: "580a560ffed849d89f3b09aba3eb0ef4" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "580a560ffed849d89f3b09aba3eb0ef4" member_type: VOTER } }
I20260812 06:20:22.011528 14889 sys_catalog.cc:458] T 00000000000000000000000000000000 P 580a560ffed849d89f3b09aba3eb0ef4 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:22.011547 14890 sys_catalog.cc:458] T 00000000000000000000000000000000 P 580a560ffed849d89f3b09aba3eb0ef4 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:22.012015 14893 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:22.013015 14893 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:22.013239 14598 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:22.014919 14893 catalog_manager.cc:1383] Generated new cluster ID: 01b9bc41467c47d7827d0ca327aeb959
I20260812 06:20:22.014984 14893 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:22.035020 14893 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:22.035851 14893 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:22.045707 14893 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 580a560ffed849d89f3b09aba3eb0ef4: Generated new TSK 0
I20260812 06:20:22.045946 14893 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:22.078078 14598 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:22.080286 14907 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:20:22.080420 14598 server_base.cc:1061] running on GCE node
W20260812 06:20:22.080295 14910 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:20:22.080508 14908 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:20:22.080868 14598 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:22.080920 14598 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:20:22.080936 14598 hybrid_clock.cc:648] HybridClock initialized: now 1786515622080936 us; error 0 us; skew 500 ppm
I20260812 06:20:22.081861 14598 webserver.cc:533] Webserver started at http://127.14.65.129:44927/ using document root <none> and password file <none>
I20260812 06:20:22.082015 14598 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:22.082056 14598 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:22.082121 14598 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:22.082562 14598 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616361105-14598-0/minicluster-data/ts-0-root/instance:
uuid: "c618ece1c943474792c85e90525898ca"
format_stamp: "Formatted at 2026-08-12 06:20:22 on dist-test-slave-8w9v"
I20260812 06:20:22.084194 14598 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:20:22.085528 14915 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:20:22.086035 14598 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:20:22.086148 14598 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616361105-14598-0/minicluster-data/ts-0-root
uuid: "c618ece1c943474792c85e90525898ca"
format_stamp: "Formatted at 2026-08-12 06:20:22 on dist-test-slave-8w9v"
I20260812 06:20:22.086236 14598 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616361105-14598-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616361105-14598-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616361105-14598-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:20:22.102931 14598 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:22.103379 14598 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:22.103711 14598 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:22.104271 14598 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:22.104328 14598 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:22.104398 14598 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:22.104430 14598 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:22.108702 14598 rpc_server.cc:307] RPC server started. Bound to: 127.14.65.129:42807
I20260812 06:20:22.109176 14986 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.14.65.129:42807 every 8 connection(s)
I20260812 06:20:22.120085 14987 heartbeater.cc:344] Connected to a master server at 127.14.65.190:39799
I20260812 06:20:22.120251 14987 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:22.120496 14987 heartbeater.cc:507] Master 127.14.65.190:39799 requested a full tablet report, sending...
I20260812 06:20:22.121212 14842 ts_manager.cc:194] Registered new tserver with Master: c618ece1c943474792c85e90525898ca (127.14.65.129:42807)
I20260812 06:20:22.121526 14598 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.012269494s
I20260812 06:20:22.122251 14842 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:50136
I20260812 06:20:22.128980 14842 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:50144:
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:20:22.137778 14946 tablet_service.cc:1511] Processing CreateTablet for tablet 11d467d20c4e433ca023ac0dd1a339fa (DEFAULT_TABLE table=heavy-update-compaction-test [id=1e2b4895eca1404294a5fbacf0e2eee2]), partition=
I20260812 06:20:22.138088 14946 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 11d467d20c4e433ca023ac0dd1a339fa. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:22.140313 15001 tablet_bootstrap.cc:492] T 11d467d20c4e433ca023ac0dd1a339fa P c618ece1c943474792c85e90525898ca: Bootstrap starting.
I20260812 06:20:22.141258 15001 tablet_bootstrap.cc:654] T 11d467d20c4e433ca023ac0dd1a339fa P c618ece1c943474792c85e90525898ca: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:22.142382 15001 tablet_bootstrap.cc:492] T 11d467d20c4e433ca023ac0dd1a339fa P c618ece1c943474792c85e90525898ca: No bootstrap required, opened a new log
I20260812 06:20:22.142496 15001 ts_tablet_manager.cc:1403] T 11d467d20c4e433ca023ac0dd1a339fa P c618ece1c943474792c85e90525898ca: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:20:22.142942 15001 raft_consensus.cc:359] T 11d467d20c4e433ca023ac0dd1a339fa P c618ece1c943474792c85e90525898ca [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c618ece1c943474792c85e90525898ca" member_type: VOTER last_known_addr { host: "127.14.65.129" port: 42807 } }
I20260812 06:20:22.143057 15001 raft_consensus.cc:385] T 11d467d20c4e433ca023ac0dd1a339fa P c618ece1c943474792c85e90525898ca [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:22.143124 15001 raft_consensus.cc:740] T 11d467d20c4e433ca023ac0dd1a339fa P c618ece1c943474792c85e90525898ca [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: c618ece1c943474792c85e90525898ca, State: Initialized, Role: FOLLOWER
I20260812 06:20:22.143298 15001 consensus_queue.cc:260] T 11d467d20c4e433ca023ac0dd1a339fa P c618ece1c943474792c85e90525898ca [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: "c618ece1c943474792c85e90525898ca" member_type: VOTER last_known_addr { host: "127.14.65.129" port: 42807 } }
I20260812 06:20:22.143390 15001 raft_consensus.cc:399] T 11d467d20c4e433ca023ac0dd1a339fa P c618ece1c943474792c85e90525898ca [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:22.143453 15001 raft_consensus.cc:493] T 11d467d20c4e433ca023ac0dd1a339fa P c618ece1c943474792c85e90525898ca [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:22.143524 15001 raft_consensus.cc:3060] T 11d467d20c4e433ca023ac0dd1a339fa P c618ece1c943474792c85e90525898ca [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:22.144332 15001 raft_consensus.cc:515] T 11d467d20c4e433ca023ac0dd1a339fa P c618ece1c943474792c85e90525898ca [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c618ece1c943474792c85e90525898ca" member_type: VOTER last_known_addr { host: "127.14.65.129" port: 42807 } }
I20260812 06:20:22.144482 15001 leader_election.cc:304] T 11d467d20c4e433ca023ac0dd1a339fa P c618ece1c943474792c85e90525898ca [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: c618ece1c943474792c85e90525898ca; no voters: 
I20260812 06:20:22.144706 15001 leader_election.cc:290] T 11d467d20c4e433ca023ac0dd1a339fa P c618ece1c943474792c85e90525898ca [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:22.144886 15003 raft_consensus.cc:2804] T 11d467d20c4e433ca023ac0dd1a339fa P c618ece1c943474792c85e90525898ca [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:22.145102 15001 ts_tablet_manager.cc:1434] T 11d467d20c4e433ca023ac0dd1a339fa P c618ece1c943474792c85e90525898ca: Time spent starting tablet: real 0.003s	user 0.001s	sys 0.002s
I20260812 06:20:22.145156 14987 heartbeater.cc:499] Master 127.14.65.190:39799 was elected leader, sending a full tablet report...
I20260812 06:20:22.145179 15003 raft_consensus.cc:697] T 11d467d20c4e433ca023ac0dd1a339fa P c618ece1c943474792c85e90525898ca [term 1 LEADER]: Becoming Leader. State: Replica: c618ece1c943474792c85e90525898ca, State: Running, Role: LEADER
I20260812 06:20:22.145390 15003 consensus_queue.cc:237] T 11d467d20c4e433ca023ac0dd1a339fa P c618ece1c943474792c85e90525898ca [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: "c618ece1c943474792c85e90525898ca" member_type: VOTER last_known_addr { host: "127.14.65.129" port: 42807 } }
I20260812 06:20:22.146840 14842 catalog_manager.cc:5719] T 11d467d20c4e433ca023ac0dd1a339fa P c618ece1c943474792c85e90525898ca reported cstate change: term changed from 0 to 1, leader changed from <none> to c618ece1c943474792c85e90525898ca (127.14.65.129). New cstate: current_term: 1 leader_uuid: "c618ece1c943474792c85e90525898ca" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c618ece1c943474792c85e90525898ca" member_type: VOTER last_known_addr { host: "127.14.65.129" port: 42807 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:22.208866 14598 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.055s	user 0.014s	sys 0.010s
I20260812 06:20:22.359915 14988 maintenance_manager.cc:419] P c618ece1c943474792c85e90525898ca: Scheduling FlushMRSOp(11d467d20c4e433ca023ac0dd1a339fa): perf score=19.054940
I20260812 06:20:22.520872 14920 maintenance_manager.cc:643] P c618ece1c943474792c85e90525898ca: FlushMRSOp(11d467d20c4e433ca023ac0dd1a339fa) complete. Timing: real 0.161s	user 0.120s	sys 0.040s Metrics: {"bytes_written":12307491,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":99,"dirs.run_cpu_time_us":269,"dirs.run_wall_time_us":964,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":39819,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1500}
I20260812 06:20:22.521968 14988 maintenance_manager.cc:419] P c618ece1c943474792c85e90525898ca: Scheduling LogGCOp(11d467d20c4e433ca023ac0dd1a339fa): free 20290830 bytes of WAL
I20260812 06:20:22.522253 14920 log_reader.cc:385] T 11d467d20c4e433ca023ac0dd1a339fa: removed 2 log segments from log reader
I20260812 06:20:22.522317 14920 log.cc:1079] T 11d467d20c4e433ca023ac0dd1a339fa P c618ece1c943474792c85e90525898ca: Deleting log segment in path: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616361105-14598-0/minicluster-data/ts-0-root/wals/11d467d20c4e433ca023ac0dd1a339fa/wal-000000001 (ops 1-6)
I20260812 06:20:22.522382 14920 log.cc:1079] T 11d467d20c4e433ca023ac0dd1a339fa P c618ece1c943474792c85e90525898ca: Deleting log segment in path: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616361105-14598-0/minicluster-data/ts-0-root/wals/11d467d20c4e433ca023ac0dd1a339fa/wal-000000002 (ops 7-10)
I20260812 06:20:22.527487 14920 maintenance_manager.cc:643] P c618ece1c943474792c85e90525898ca: LogGCOp(11d467d20c4e433ca023ac0dd1a339fa) complete. Timing: real 0.005s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:20:22.527981 14988 maintenance_manager.cc:419] P c618ece1c943474792c85e90525898ca: Scheduling FlushDeltaMemStoresOp(11d467d20c4e433ca023ac0dd1a339fa): perf score=2.188937
I20260812 06:20:22.560485 14920 maintenance_manager.cc:643] P c618ece1c943474792c85e90525898ca: FlushDeltaMemStoresOp(11d467d20c4e433ca023ac0dd1a339fa) complete. Timing: real 0.032s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5291,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.560971 14988 maintenance_manager.cc:419] P c618ece1c943474792c85e90525898ca: Scheduling FlushDeltaMemStoresOp(11d467d20c4e433ca023ac0dd1a339fa): perf score=2.188937
I20260812 06:20:22.572573 14920 maintenance_manager.cc:643] P c618ece1c943474792c85e90525898ca: FlushDeltaMemStoresOp(11d467d20c4e433ca023ac0dd1a339fa) complete. Timing: real 0.011s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4327,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.573161 14988 maintenance_manager.cc:419] P c618ece1c943474792c85e90525898ca: Scheduling MajorDeltaCompactionOp(11d467d20c4e433ca023ac0dd1a339fa): perf score=1.000000
I20260812 06:20:22.761145 14920 maintenance_manager.cc:643] P c618ece1c943474792c85e90525898ca: MajorDeltaCompactionOp(11d467d20c4e433ca023ac0dd1a339fa) complete. Timing: real 0.188s	user 0.119s	sys 0.067s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774808,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":854,"lbm_read_time_us":12801,"lbm_reads_lt_1ms":573,"lbm_write_time_us":30410,"lbm_writes_lt_1ms":543,"mutex_wait_us":26,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3584,"thread_start_us":355,"threads_started":5,"update_count":2500}
I20260812 06:20:22.761780 14988 maintenance_manager.cc:419] P c618ece1c943474792c85e90525898ca: Scheduling FlushDeltaMemStoresOp(11d467d20c4e433ca023ac0dd1a339fa): perf score=14.095187
I20260812 06:20:22.824996 14920 maintenance_manager.cc:643] P c618ece1c943474792c85e90525898ca: FlushDeltaMemStoresOp(11d467d20c4e433ca023ac0dd1a339fa) complete. Timing: real 0.063s	user 0.031s	sys 0.031s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21063,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:22.825501 14988 maintenance_manager.cc:419] P c618ece1c943474792c85e90525898ca: Scheduling FlushDeltaMemStoresOp(11d467d20c4e433ca023ac0dd1a339fa): perf score=2.188937
I20260812 06:20:22.836531 14920 maintenance_manager.cc:643] P c618ece1c943474792c85e90525898ca: FlushDeltaMemStoresOp(11d467d20c4e433ca023ac0dd1a339fa) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4265,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.837030 14988 maintenance_manager.cc:419] P c618ece1c943474792c85e90525898ca: Scheduling MajorDeltaCompactionOp(11d467d20c4e433ca023ac0dd1a339fa): perf score=1.000000
I20260812 06:20:23.016539 14920 maintenance_manager.cc:643] P c618ece1c943474792c85e90525898ca: MajorDeltaCompactionOp(11d467d20c4e433ca023ac0dd1a339fa) complete. Timing: real 0.179s	user 0.116s	sys 0.064s 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":172,"lbm_read_time_us":12435,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30557,"lbm_writes_lt_1ms":543,"mutex_wait_us":3,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12800,"update_count":2500}
I20260812 06:20:23.017195 14988 maintenance_manager.cc:419] P c618ece1c943474792c85e90525898ca: Scheduling FlushDeltaMemStoresOp(11d467d20c4e433ca023ac0dd1a339fa): perf score=10.126437
I20260812 06:20:23.063797 14920 maintenance_manager.cc:643] P c618ece1c943474792c85e90525898ca: FlushDeltaMemStoresOp(11d467d20c4e433ca023ac0dd1a339fa) complete. Timing: real 0.046s	user 0.025s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":21718,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:20:23.064344 14988 maintenance_manager.cc:419] P c618ece1c943474792c85e90525898ca: Scheduling UndoDeltaBlockGCOp(11d467d20c4e433ca023ac0dd1a339fa): 16411392 bytes on disk
I20260812 06:20:23.064767 14920 maintenance_manager.cc:643] P c618ece1c943474792c85e90525898ca: UndoDeltaBlockGCOp(11d467d20c4e433ca023ac0dd1a339fa) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4}
I20260812 06:20:23.065147 14988 maintenance_manager.cc:419] P c618ece1c943474792c85e90525898ca: Scheduling FlushDeltaMemStoresOp(11d467d20c4e433ca023ac0dd1a339fa): perf score=2.188937
I20260812 06:20:23.089320 14920 maintenance_manager.cc:643] P c618ece1c943474792c85e90525898ca: FlushDeltaMemStoresOp(11d467d20c4e433ca023ac0dd1a339fa) complete. Timing: real 0.024s	user 0.009s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6397,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:23.089780 14988 maintenance_manager.cc:419] P c618ece1c943474792c85e90525898ca: Scheduling FlushDeltaMemStoresOp(11d467d20c4e433ca023ac0dd1a339fa): perf score=2.188937
I20260812 06:20:23.111609 14920 maintenance_manager.cc:643] P c618ece1c943474792c85e90525898ca: FlushDeltaMemStoresOp(11d467d20c4e433ca023ac0dd1a339fa) complete. Timing: real 0.022s	user 0.004s	sys 0.014s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4283,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:23.112398 14988 maintenance_manager.cc:419] P c618ece1c943474792c85e90525898ca: Scheduling MajorDeltaCompactionOp(11d467d20c4e433ca023ac0dd1a339fa): perf score=1.000000
I20260812 06:20:23.319733 14920 maintenance_manager.cc:643] P c618ece1c943474792c85e90525898ca: MajorDeltaCompactionOp(11d467d20c4e433ca023ac0dd1a339fa) complete. Timing: real 0.207s	user 0.133s	sys 0.069s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774808,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":203,"lbm_read_time_us":13915,"lbm_reads_lt_1ms":573,"lbm_write_time_us":35585,"lbm_writes_lt_1ms":543,"mutex_wait_us":23,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13696,"update_count":2500}
I20260812 06:20:23.320468 14988 maintenance_manager.cc:419] P c618ece1c943474792c85e90525898ca: Scheduling FlushDeltaMemStoresOp(11d467d20c4e433ca023ac0dd1a339fa): perf score=14.095187
I20260812 06:20:23.369333 14920 maintenance_manager.cc:643] P c618ece1c943474792c85e90525898ca: FlushDeltaMemStoresOp(11d467d20c4e433ca023ac0dd1a339fa) complete. Timing: real 0.049s	user 0.022s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21261,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:23.369854 14988 maintenance_manager.cc:419] P c618ece1c943474792c85e90525898ca: Scheduling FlushDeltaMemStoresOp(11d467d20c4e433ca023ac0dd1a339fa): perf score=2.188937
I20260812 06:20:23.383234 14920 maintenance_manager.cc:643] P c618ece1c943474792c85e90525898ca: FlushDeltaMemStoresOp(11d467d20c4e433ca023ac0dd1a339fa) complete. Timing: real 0.013s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4729,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:23.383976 14988 maintenance_manager.cc:419] P c618ece1c943474792c85e90525898ca: Scheduling MajorDeltaCompactionOp(11d467d20c4e433ca023ac0dd1a339fa): perf score=1.000000
I20260812 06:20:23.559604 14920 maintenance_manager.cc:643] P c618ece1c943474792c85e90525898ca: MajorDeltaCompactionOp(11d467d20c4e433ca023ac0dd1a339fa) complete. Timing: real 0.175s	user 0.136s	sys 0.034s 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":496,"lbm_read_time_us":10079,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29126,"lbm_writes_lt_1ms":543,"mutex_wait_us":292,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2944,"update_count":2500}
I20260812 06:20:23.560302 14988 maintenance_manager.cc:419] P c618ece1c943474792c85e90525898ca: Scheduling FlushDeltaMemStoresOp(11d467d20c4e433ca023ac0dd1a339fa): perf score=14.095187
I20260812 06:20:23.607965 14920 maintenance_manager.cc:643] P c618ece1c943474792c85e90525898ca: FlushDeltaMemStoresOp(11d467d20c4e433ca023ac0dd1a339fa) complete. Timing: real 0.047s	user 0.022s	sys 0.021s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20541,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:23.608551 14988 maintenance_manager.cc:419] P c618ece1c943474792c85e90525898ca: Scheduling FlushDeltaMemStoresOp(11d467d20c4e433ca023ac0dd1a339fa): perf score=2.188937
I20260812 06:20:23.625098 14920 maintenance_manager.cc:643] P c618ece1c943474792c85e90525898ca: FlushDeltaMemStoresOp(11d467d20c4e433ca023ac0dd1a339fa) complete. Timing: real 0.016s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6202,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:23.625627 14988 maintenance_manager.cc:419] P c618ece1c943474792c85e90525898ca: Scheduling MajorDeltaCompactionOp(11d467d20c4e433ca023ac0dd1a339fa): perf score=1.000000
I20260812 06:20:23.776808 14920 maintenance_manager.cc:643] P c618ece1c943474792c85e90525898ca: MajorDeltaCompactionOp(11d467d20c4e433ca023ac0dd1a339fa) complete. Timing: real 0.151s	user 0.093s	sys 0.057s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":175,"lbm_read_time_us":9151,"lbm_reads_lt_1ms":568,"lbm_write_time_us":31985,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":2500}
I20260812 06:20:23.777705 14988 maintenance_manager.cc:419] P c618ece1c943474792c85e90525898ca: Scheduling FlushDeltaMemStoresOp(11d467d20c4e433ca023ac0dd1a339fa): perf score=10.126437
I20260812 06:20:23.813987 14920 maintenance_manager.cc:643] P c618ece1c943474792c85e90525898ca: FlushDeltaMemStoresOp(11d467d20c4e433ca023ac0dd1a339fa) complete. Timing: real 0.036s	user 0.030s	sys 0.004s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15627,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:23.814566 14988 maintenance_manager.cc:419] P c618ece1c943474792c85e90525898ca: Scheduling FlushDeltaMemStoresOp(11d467d20c4e433ca023ac0dd1a339fa): perf score=2.188937
I20260812 06:20:23.831909 14920 maintenance_manager.cc:643] P c618ece1c943474792c85e90525898ca: FlushDeltaMemStoresOp(11d467d20c4e433ca023ac0dd1a339fa) complete. Timing: real 0.017s	user 0.007s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6663,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:23.832650 14988 maintenance_manager.cc:419] P c618ece1c943474792c85e90525898ca: Scheduling FlushMRSOp(11d467d20c4e433ca023ac0dd1a339fa): perf score=1.000000
I20260812 06:20:23.884804 14920 maintenance_manager.cc:643] P c618ece1c943474792c85e90525898ca: FlushMRSOp(11d467d20c4e433ca023ac0dd1a339fa) complete. Timing: real 0.052s	user 0.030s	sys 0.000s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":90,"dirs.run_cpu_time_us":258,"dirs.run_wall_time_us":1539,"drs_written":1,"lbm_read_time_us":63,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2457,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:20:23.885681 14988 maintenance_manager.cc:419] P c618ece1c943474792c85e90525898ca: Scheduling LogGCOp(11d467d20c4e433ca023ac0dd1a339fa): free 112692307 bytes of WAL
I20260812 06:20:23.885973 14920 log_reader.cc:385] T 11d467d20c4e433ca023ac0dd1a339fa: removed 11 log segments from log reader
I20260812 06:20:23.886046 14920 log.cc:1079] T 11d467d20c4e433ca023ac0dd1a339fa P c618ece1c943474792c85e90525898ca: Deleting log segment in path: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616361105-14598-0/minicluster-data/ts-0-root/wals/11d467d20c4e433ca023ac0dd1a339fa/wal-000000003 (ops 11-15)
I20260812 06:20:23.886101 14920 log.cc:1079] T 11d467d20c4e433ca023ac0dd1a339fa P c618ece1c943474792c85e90525898ca: Deleting log segment in path: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616361105-14598-0/minicluster-data/ts-0-root/wals/11d467d20c4e433ca023ac0dd1a339fa/wal-000000004 (ops 16-20)
I20260812 06:20:23.886155 14920 log.cc:1079] T 11d467d20c4e433ca023ac0dd1a339fa P c618ece1c943474792c85e90525898ca: Deleting log segment in path: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616361105-14598-0/minicluster-data/ts-0-root/wals/11d467d20c4e433ca023ac0dd1a339fa/wal-000000005 (ops 21-25)
I20260812 06:20:23.886196 14920 log.cc:1079] T 11d467d20c4e433ca023ac0dd1a339fa P c618ece1c943474792c85e90525898ca: Deleting log segment in path: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616361105-14598-0/minicluster-data/ts-0-root/wals/11d467d20c4e433ca023ac0dd1a339fa/wal-000000006 (ops 26-30)
I20260812 06:20:23.886231 14920 log.cc:1079] T 11d467d20c4e433ca023ac0dd1a339fa P c618ece1c943474792c85e90525898ca: Deleting log segment in path: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616361105-14598-0/minicluster-data/ts-0-root/wals/11d467d20c4e433ca023ac0dd1a339fa/wal-000000007 (ops 31-35)
I20260812 06:20:23.886268 14920 log.cc:1079] T 11d467d20c4e433ca023ac0dd1a339fa P c618ece1c943474792c85e90525898ca: Deleting log segment in path: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616361105-14598-0/minicluster-data/ts-0-root/wals/11d467d20c4e433ca023ac0dd1a339fa/wal-000000008 (ops 36-40)
I20260812 06:20:23.886305 14920 log.cc:1079] T 11d467d20c4e433ca023ac0dd1a339fa P c618ece1c943474792c85e90525898ca: Deleting log segment in path: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616361105-14598-0/minicluster-data/ts-0-root/wals/11d467d20c4e433ca023ac0dd1a339fa/wal-000000009 (ops 41-45)
I20260812 06:20:23.886343 14920 log.cc:1079] T 11d467d20c4e433ca023ac0dd1a339fa P c618ece1c943474792c85e90525898ca: Deleting log segment in path: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616361105-14598-0/minicluster-data/ts-0-root/wals/11d467d20c4e433ca023ac0dd1a339fa/wal-000000010 (ops 46-50)
I20260812 06:20:23.886380 14920 log.cc:1079] T 11d467d20c4e433ca023ac0dd1a339fa P c618ece1c943474792c85e90525898ca: Deleting log segment in path: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616361105-14598-0/minicluster-data/ts-0-root/wals/11d467d20c4e433ca023ac0dd1a339fa/wal-000000011 (ops 51-55)
I20260812 06:20:23.886415 14920 log.cc:1079] T 11d467d20c4e433ca023ac0dd1a339fa P c618ece1c943474792c85e90525898ca: Deleting log segment in path: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616361105-14598-0/minicluster-data/ts-0-root/wals/11d467d20c4e433ca023ac0dd1a339fa/wal-000000012 (ops 56-60)
I20260812 06:20:23.886454 14920 log.cc:1079] T 11d467d20c4e433ca023ac0dd1a339fa P c618ece1c943474792c85e90525898ca: Deleting log segment in path: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616361105-14598-0/minicluster-data/ts-0-root/wals/11d467d20c4e433ca023ac0dd1a339fa/wal-000000013 (ops 61-65)
I20260812 06:20:23.909730 14920 maintenance_manager.cc:643] P c618ece1c943474792c85e90525898ca: LogGCOp(11d467d20c4e433ca023ac0dd1a339fa) complete. Timing: real 0.024s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:20:23.910219 14988 maintenance_manager.cc:419] P c618ece1c943474792c85e90525898ca: Scheduling FlushDeltaMemStoresOp(11d467d20c4e433ca023ac0dd1a339fa): perf score=6.157687
I20260812 06:20:23.935503 14920 maintenance_manager.cc:643] P c618ece1c943474792c85e90525898ca: FlushDeltaMemStoresOp(11d467d20c4e433ca023ac0dd1a339fa) complete. Timing: real 0.025s	user 0.015s	sys 0.007s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":10435,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:20:23.936064 14988 maintenance_manager.cc:419] P c618ece1c943474792c85e90525898ca: Scheduling LogGCOp(11d467d20c4e433ca023ac0dd1a339fa): free 8767174 bytes of WAL
I20260812 06:20:23.936373 14920 log_reader.cc:385] T 11d467d20c4e433ca023ac0dd1a339fa: removed 1 log segments from log reader
I20260812 06:20:23.936442 14920 log.cc:1079] T 11d467d20c4e433ca023ac0dd1a339fa P c618ece1c943474792c85e90525898ca: Deleting log segment in path: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616361105-14598-0/minicluster-data/ts-0-root/wals/11d467d20c4e433ca023ac0dd1a339fa/wal-000000014 (ops 66-70)
I20260812 06:20:23.938683 14920 maintenance_manager.cc:643] P c618ece1c943474792c85e90525898ca: LogGCOp(11d467d20c4e433ca023ac0dd1a339fa) complete. Timing: real 0.002s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:20:23.939113 14988 maintenance_manager.cc:419] P c618ece1c943474792c85e90525898ca: Scheduling FlushDeltaMemStoresOp(11d467d20c4e433ca023ac0dd1a339fa): perf score=2.188937
I20260812 06:20:23.958956 14920 maintenance_manager.cc:643] P c618ece1c943474792c85e90525898ca: FlushDeltaMemStoresOp(11d467d20c4e433ca023ac0dd1a339fa) complete. Timing: real 0.020s	user 0.017s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":7381,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:23.959543 14988 maintenance_manager.cc:419] P c618ece1c943474792c85e90525898ca: Scheduling UndoDeltaBlockGCOp(11d467d20c4e433ca023ac0dd1a339fa): 473 bytes on disk
I20260812 06:20:23.959962 14920 maintenance_manager.cc:643] P c618ece1c943474792c85e90525898ca: UndoDeltaBlockGCOp(11d467d20c4e433ca023ac0dd1a339fa) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4}
I20260812 06:20:23.960582 14988 maintenance_manager.cc:419] P c618ece1c943474792c85e90525898ca: Scheduling MajorDeltaCompactionOp(11d467d20c4e433ca023ac0dd1a339fa): perf score=1.000000
I20260812 06:20:24.195042 14920 maintenance_manager.cc:643] P c618ece1c943474792c85e90525898ca: MajorDeltaCompactionOp(11d467d20c4e433ca023ac0dd1a339fa) complete. Timing: real 0.234s	user 0.167s	sys 0.067s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979751,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":324,"lbm_read_time_us":18126,"lbm_reads_lt_1ms":766,"lbm_write_time_us":37092,"lbm_writes_lt_1ms":743,"mutex_wait_us":51,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":26752,"thread_start_us":101,"threads_started":1,"update_count":3500}
I20260812 06:20:24.195797 14988 maintenance_manager.cc:419] P c618ece1c943474792c85e90525898ca: Scheduling FlushDeltaMemStoresOp(11d467d20c4e433ca023ac0dd1a339fa): perf score=18.063937
I20260812 06:20:24.259266 14920 maintenance_manager.cc:643] P c618ece1c943474792c85e90525898ca: FlushDeltaMemStoresOp(11d467d20c4e433ca023ac0dd1a339fa) complete. Timing: real 0.063s	user 0.028s	sys 0.031s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":31941,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":500,"reinsert_count":0,"update_count":2500}
I20260812 06:20:24.259852 14988 maintenance_manager.cc:419] P c618ece1c943474792c85e90525898ca: Scheduling FlushDeltaMemStoresOp(11d467d20c4e433ca023ac0dd1a339fa): perf score=2.188937
I20260812 06:20:24.276382 14920 maintenance_manager.cc:643] P c618ece1c943474792c85e90525898ca: FlushDeltaMemStoresOp(11d467d20c4e433ca023ac0dd1a339fa) complete. Timing: real 0.016s	user 0.013s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6502,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:24.276849 14988 maintenance_manager.cc:419] P c618ece1c943474792c85e90525898ca: Scheduling MajorDeltaCompactionOp(11d467d20c4e433ca023ac0dd1a339fa): perf score=1.000000
I20260812 06:20:24.511452 14920 maintenance_manager.cc:643] P c618ece1c943474792c85e90525898ca: MajorDeltaCompactionOp(11d467d20c4e433ca023ac0dd1a339fa) complete. Timing: real 0.234s	user 0.152s	sys 0.071s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877103,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1174,"lbm_read_time_us":16770,"lbm_reads_lt_1ms":668,"lbm_write_time_us":35012,"lbm_writes_lt_1ms":643,"mutex_wait_us":270,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":3000}
I20260812 06:20:24.512244 14988 maintenance_manager.cc:419] P c618ece1c943474792c85e90525898ca: Scheduling FlushDeltaMemStoresOp(11d467d20c4e433ca023ac0dd1a339fa): perf score=18.063937
I20260812 06:20:24.583170 14920 maintenance_manager.cc:643] P c618ece1c943474792c85e90525898ca: FlushDeltaMemStoresOp(11d467d20c4e433ca023ac0dd1a339fa) complete. Timing: real 0.071s	user 0.038s	sys 0.016s Metrics: {"bytes_written":20512318,"delete_count":0,"lbm_write_time_us":26123,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:24.583667 14988 maintenance_manager.cc:419] P c618ece1c943474792c85e90525898ca: Scheduling FlushDeltaMemStoresOp(11d467d20c4e433ca023ac0dd1a339fa): perf score=2.188937
I20260812 06:20:24.595935 14920 maintenance_manager.cc:643] P c618ece1c943474792c85e90525898ca: FlushDeltaMemStoresOp(11d467d20c4e433ca023ac0dd1a339fa) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4153,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:24.596655 14988 maintenance_manager.cc:419] P c618ece1c943474792c85e90525898ca: Scheduling MajorDeltaCompactionOp(11d467d20c4e433ca023ac0dd1a339fa): perf score=1.000000
I20260812 06:20:24.800242 14920 maintenance_manager.cc:643] P c618ece1c943474792c85e90525898ca: MajorDeltaCompactionOp(11d467d20c4e433ca023ac0dd1a339fa) complete. Timing: real 0.203s	user 0.148s	sys 0.055s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877105,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":198,"lbm_read_time_us":13484,"lbm_reads_lt_1ms":672,"lbm_write_time_us":37531,"lbm_writes_lt_1ms":643,"mutex_wait_us":32,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":3000}
I20260812 06:20:24.801013 14988 maintenance_manager.cc:419] P c618ece1c943474792c85e90525898ca: Scheduling FlushDeltaMemStoresOp(11d467d20c4e433ca023ac0dd1a339fa): perf score=14.095187
I20260812 06:20:24.849556 14920 maintenance_manager.cc:643] P c618ece1c943474792c85e90525898ca: FlushDeltaMemStoresOp(11d467d20c4e433ca023ac0dd1a339fa) complete. Timing: real 0.048s	user 0.039s	sys 0.008s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21826,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:24.850101 14988 maintenance_manager.cc:419] P c618ece1c943474792c85e90525898ca: Scheduling FlushDeltaMemStoresOp(11d467d20c4e433ca023ac0dd1a339fa): perf score=2.188937
I20260812 06:20:24.867949 14920 maintenance_manager.cc:643] P c618ece1c943474792c85e90525898ca: FlushDeltaMemStoresOp(11d467d20c4e433ca023ac0dd1a339fa) complete. Timing: real 0.018s	user 0.011s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6815,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:24.868530 14988 maintenance_manager.cc:419] P c618ece1c943474792c85e90525898ca: Scheduling MajorDeltaCompactionOp(11d467d20c4e433ca023ac0dd1a339fa): perf score=1.000000
I20260812 06:20:25.053627 14920 maintenance_manager.cc:643] P c618ece1c943474792c85e90525898ca: MajorDeltaCompactionOp(11d467d20c4e433ca023ac0dd1a339fa) complete. Timing: real 0.185s	user 0.134s	sys 0.050s 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":1219,"lbm_read_time_us":11067,"lbm_reads_lt_1ms":564,"lbm_write_time_us":35836,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:20:25.054430 14988 maintenance_manager.cc:419] P c618ece1c943474792c85e90525898ca: Scheduling FlushDeltaMemStoresOp(11d467d20c4e433ca023ac0dd1a339fa): perf score=14.095187
I20260812 06:20:25.109539 14920 maintenance_manager.cc:643] P c618ece1c943474792c85e90525898ca: FlushDeltaMemStoresOp(11d467d20c4e433ca023ac0dd1a339fa) complete. Timing: real 0.055s	user 0.034s	sys 0.019s Metrics: {"bytes_written":16409898,"delete_count":0,"lbm_write_time_us":20047,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:25.110075 14988 maintenance_manager.cc:419] P c618ece1c943474792c85e90525898ca: Scheduling FlushDeltaMemStoresOp(11d467d20c4e433ca023ac0dd1a339fa): perf score=2.188937
I20260812 06:20:25.121395 14920 maintenance_manager.cc:643] P c618ece1c943474792c85e90525898ca: FlushDeltaMemStoresOp(11d467d20c4e433ca023ac0dd1a339fa) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4382,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:25.121855 14988 maintenance_manager.cc:419] P c618ece1c943474792c85e90525898ca: Scheduling MajorDeltaCompactionOp(11d467d20c4e433ca023ac0dd1a339fa): perf score=1.000000
I20260812 06:20:25.309442 14920 maintenance_manager.cc:643] P c618ece1c943474792c85e90525898ca: MajorDeltaCompactionOp(11d467d20c4e433ca023ac0dd1a339fa) complete. Timing: real 0.187s	user 0.131s	sys 0.051s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":251,"lbm_read_time_us":14240,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32558,"lbm_writes_lt_1ms":543,"mutex_wait_us":23,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13568,"update_count":2500}
I20260812 06:20:25.310113 14988 maintenance_manager.cc:419] P c618ece1c943474792c85e90525898ca: Scheduling FlushDeltaMemStoresOp(11d467d20c4e433ca023ac0dd1a339fa): perf score=14.095187
I20260812 06:20:25.378770 14920 maintenance_manager.cc:643] P c618ece1c943474792c85e90525898ca: FlushDeltaMemStoresOp(11d467d20c4e433ca023ac0dd1a339fa) complete. Timing: real 0.068s	user 0.043s	sys 0.011s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21544,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:25.379288 14988 maintenance_manager.cc:419] P c618ece1c943474792c85e90525898ca: Scheduling FlushDeltaMemStoresOp(11d467d20c4e433ca023ac0dd1a339fa): perf score=2.188937
I20260812 06:20:25.390194 14920 maintenance_manager.cc:643] P c618ece1c943474792c85e90525898ca: FlushDeltaMemStoresOp(11d467d20c4e433ca023ac0dd1a339fa) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4431,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:25.390791 14988 maintenance_manager.cc:419] P c618ece1c943474792c85e90525898ca: Scheduling FlushMRSOp(11d467d20c4e433ca023ac0dd1a339fa): perf score=1.000000
I20260812 06:20:25.432586 14920 maintenance_manager.cc:643] P c618ece1c943474792c85e90525898ca: FlushMRSOp(11d467d20c4e433ca023ac0dd1a339fa) complete. Timing: real 0.042s	user 0.034s	sys 0.000s Metrics: {"bytes_written":1193509,"cfile_init":1,"dirs.queue_time_us":66,"dirs.run_cpu_time_us":251,"dirs.run_wall_time_us":1560,"drs_written":1,"lbm_read_time_us":92,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1516,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:20:25.433337 14988 maintenance_manager.cc:419] P c618ece1c943474792c85e90525898ca: Scheduling LogGCOp(11d467d20c4e433ca023ac0dd1a339fa): free 123804191 bytes of WAL
I20260812 06:20:25.433588 14920 log_reader.cc:385] T 11d467d20c4e433ca023ac0dd1a339fa: removed 12 log segments from log reader
I20260812 06:20:25.433667 14920 log.cc:1079] T 11d467d20c4e433ca023ac0dd1a339fa P c618ece1c943474792c85e90525898ca: Deleting log segment in path: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616361105-14598-0/minicluster-data/ts-0-root/wals/11d467d20c4e433ca023ac0dd1a339fa/wal-000000015 (ops 71-74)
I20260812 06:20:25.433723 14920 log.cc:1079] T 11d467d20c4e433ca023ac0dd1a339fa P c618ece1c943474792c85e90525898ca: Deleting log segment in path: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616361105-14598-0/minicluster-data/ts-0-root/wals/11d467d20c4e433ca023ac0dd1a339fa/wal-000000016 (ops 75-79)
I20260812 06:20:25.433758 14920 log.cc:1079] T 11d467d20c4e433ca023ac0dd1a339fa P c618ece1c943474792c85e90525898ca: Deleting log segment in path: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616361105-14598-0/minicluster-data/ts-0-root/wals/11d467d20c4e433ca023ac0dd1a339fa/wal-000000017 (ops 80-84)
I20260812 06:20:25.433794 14920 log.cc:1079] T 11d467d20c4e433ca023ac0dd1a339fa P c618ece1c943474792c85e90525898ca: Deleting log segment in path: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616361105-14598-0/minicluster-data/ts-0-root/wals/11d467d20c4e433ca023ac0dd1a339fa/wal-000000018 (ops 85-89)
I20260812 06:20:25.433830 14920 log.cc:1079] T 11d467d20c4e433ca023ac0dd1a339fa P c618ece1c943474792c85e90525898ca: Deleting log segment in path: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616361105-14598-0/minicluster-data/ts-0-root/wals/11d467d20c4e433ca023ac0dd1a339fa/wal-000000019 (ops 90-94)
I20260812 06:20:25.433861 14920 log.cc:1079] T 11d467d20c4e433ca023ac0dd1a339fa P c618ece1c943474792c85e90525898ca: Deleting log segment in path: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616361105-14598-0/minicluster-data/ts-0-root/wals/11d467d20c4e433ca023ac0dd1a339fa/wal-000000020 (ops 95-98)
I20260812 06:20:25.433898 14920 log.cc:1079] T 11d467d20c4e433ca023ac0dd1a339fa P c618ece1c943474792c85e90525898ca: Deleting log segment in path: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616361105-14598-0/minicluster-data/ts-0-root/wals/11d467d20c4e433ca023ac0dd1a339fa/wal-000000021 (ops 99-103)
I20260812 06:20:25.433938 14920 log.cc:1079] T 11d467d20c4e433ca023ac0dd1a339fa P c618ece1c943474792c85e90525898ca: Deleting log segment in path: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616361105-14598-0/minicluster-data/ts-0-root/wals/11d467d20c4e433ca023ac0dd1a339fa/wal-000000022 (ops 104-108)
I20260812 06:20:25.433979 14920 log.cc:1079] T 11d467d20c4e433ca023ac0dd1a339fa P c618ece1c943474792c85e90525898ca: Deleting log segment in path: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616361105-14598-0/minicluster-data/ts-0-root/wals/11d467d20c4e433ca023ac0dd1a339fa/wal-000000023 (ops 109-113)
I20260812 06:20:25.434020 14920 log.cc:1079] T 11d467d20c4e433ca023ac0dd1a339fa P c618ece1c943474792c85e90525898ca: Deleting log segment in path: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616361105-14598-0/minicluster-data/ts-0-root/wals/11d467d20c4e433ca023ac0dd1a339fa/wal-000000024 (ops 114-118)
I20260812 06:20:25.434059 14920 log.cc:1079] T 11d467d20c4e433ca023ac0dd1a339fa P c618ece1c943474792c85e90525898ca: Deleting log segment in path: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616361105-14598-0/minicluster-data/ts-0-root/wals/11d467d20c4e433ca023ac0dd1a339fa/wal-000000025 (ops 119-123)
I20260812 06:20:25.434098 14920 log.cc:1079] T 11d467d20c4e433ca023ac0dd1a339fa P c618ece1c943474792c85e90525898ca: Deleting log segment in path: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616361105-14598-0/minicluster-data/ts-0-root/wals/11d467d20c4e433ca023ac0dd1a339fa/wal-000000026 (ops 124-128)
I20260812 06:20:25.460451 14920 maintenance_manager.cc:643] P c618ece1c943474792c85e90525898ca: LogGCOp(11d467d20c4e433ca023ac0dd1a339fa) complete. Timing: real 0.027s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:20:25.460884 14988 maintenance_manager.cc:419] P c618ece1c943474792c85e90525898ca: Scheduling FlushDeltaMemStoresOp(11d467d20c4e433ca023ac0dd1a339fa): perf score=3.181125
I20260812 06:20:25.477941 14920 maintenance_manager.cc:643] P c618ece1c943474792c85e90525898ca: FlushDeltaMemStoresOp(11d467d20c4e433ca023ac0dd1a339fa) complete. Timing: real 0.017s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4941,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:25.478469 14988 maintenance_manager.cc:419] P c618ece1c943474792c85e90525898ca: Scheduling UndoDeltaBlockGCOp(11d467d20c4e433ca023ac0dd1a339fa): 462 bytes on disk
I20260812 06:20:25.478914 14920 maintenance_manager.cc:643] P c618ece1c943474792c85e90525898ca: UndoDeltaBlockGCOp(11d467d20c4e433ca023ac0dd1a339fa) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":69,"lbm_reads_lt_1ms":4}
I20260812 06:20:25.479451 14988 maintenance_manager.cc:419] P c618ece1c943474792c85e90525898ca: Scheduling FlushDeltaMemStoresOp(11d467d20c4e433ca023ac0dd1a339fa): perf score=2.188937
I20260812 06:20:25.490324 14920 maintenance_manager.cc:643] P c618ece1c943474792c85e90525898ca: FlushDeltaMemStoresOp(11d467d20c4e433ca023ac0dd1a339fa) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4029,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:25.491149 14988 maintenance_manager.cc:419] P c618ece1c943474792c85e90525898ca: Scheduling MajorDeltaCompactionOp(11d467d20c4e433ca023ac0dd1a339fa): perf score=1.000000
I20260812 06:20:25.715457 14920 maintenance_manager.cc:643] P c618ece1c943474792c85e90525898ca: MajorDeltaCompactionOp(11d467d20c4e433ca023ac0dd1a339fa) complete. Timing: real 0.224s	user 0.161s	sys 0.059s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979737,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":940,"lbm_read_time_us":18188,"lbm_reads_lt_1ms":774,"lbm_write_time_us":38116,"lbm_writes_lt_1ms":743,"mutex_wait_us":387,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":9984,"thread_start_us":88,"threads_started":1,"update_count":3500}
I20260812 06:20:25.716439 14988 maintenance_manager.cc:419] P c618ece1c943474792c85e90525898ca: Scheduling FlushDeltaMemStoresOp(11d467d20c4e433ca023ac0dd1a339fa): perf score=15.087375
I20260812 06:20:25.779696 14920 maintenance_manager.cc:643] P c618ece1c943474792c85e90525898ca: FlushDeltaMemStoresOp(11d467d20c4e433ca023ac0dd1a339fa) complete. Timing: real 0.063s	user 0.011s	sys 0.035s Metrics: {"bytes_written":16861173,"delete_count":0,"lbm_write_time_us":22754,"lbm_writes_lt_1ms":414,"reinsert_count":0,"update_count":2055}
I20260812 06:20:25.780215 14988 maintenance_manager.cc:419] P c618ece1c943474792c85e90525898ca: Scheduling FlushDeltaMemStoresOp(11d467d20c4e433ca023ac0dd1a339fa): perf score=6.157687
I20260812 06:20:25.805383 14920 maintenance_manager.cc:643] P c618ece1c943474792c85e90525898ca: FlushDeltaMemStoresOp(11d467d20c4e433ca023ac0dd1a339fa) complete. Timing: real 0.025s	user 0.018s	sys 0.004s Metrics: {"bytes_written":7753813,"delete_count":0,"lbm_write_time_us":10395,"lbm_writes_lt_1ms":192,"reinsert_count":0,"update_count":945}
I20260812 06:20:25.805887 14988 maintenance_manager.cc:419] P c618ece1c943474792c85e90525898ca: Scheduling MajorDeltaCompactionOp(11d467d20c4e433ca023ac0dd1a339fa): perf score=1.000000
I20260812 06:20:25.974721 14920 maintenance_manager.cc:643] P c618ece1c943474792c85e90525898ca: MajorDeltaCompactionOp(11d467d20c4e433ca023ac0dd1a339fa) complete. Timing: real 0.169s	user 0.136s	sys 0.032s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877108,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":249,"lbm_read_time_us":12888,"lbm_reads_lt_1ms":664,"lbm_write_time_us":36511,"lbm_writes_lt_1ms":643,"mutex_wait_us":43,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":5376,"update_count":3000}
I20260812 06:20:25.975260 14988 maintenance_manager.cc:419] P c618ece1c943474792c85e90525898ca: Scheduling FlushDeltaMemStoresOp(11d467d20c4e433ca023ac0dd1a339fa): perf score=14.095187
I20260812 06:20:26.022159 14920 maintenance_manager.cc:643] P c618ece1c943474792c85e90525898ca: FlushDeltaMemStoresOp(11d467d20c4e433ca023ac0dd1a339fa) complete. Timing: real 0.047s	user 0.029s	sys 0.016s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":20884,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:26.022717 14988 maintenance_manager.cc:419] P c618ece1c943474792c85e90525898ca: Scheduling FlushDeltaMemStoresOp(11d467d20c4e433ca023ac0dd1a339fa): perf score=2.188937
I20260812 06:20:26.035876 14920 maintenance_manager.cc:643] P c618ece1c943474792c85e90525898ca: FlushDeltaMemStoresOp(11d467d20c4e433ca023ac0dd1a339fa) complete. Timing: real 0.013s	user 0.003s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4523,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:26.036504 14988 maintenance_manager.cc:419] P c618ece1c943474792c85e90525898ca: Scheduling MajorDeltaCompactionOp(11d467d20c4e433ca023ac0dd1a339fa): perf score=1.000000
I20260812 06:20:26.200305 14920 maintenance_manager.cc:643] P c618ece1c943474792c85e90525898ca: MajorDeltaCompactionOp(11d467d20c4e433ca023ac0dd1a339fa) complete. Timing: real 0.164s	user 0.104s	sys 0.057s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774691,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":2087,"lbm_read_time_us":12077,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31530,"lbm_writes_lt_1ms":543,"mutex_wait_us":1487,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":19840,"update_count":2500}
I20260812 06:20:26.201045 14988 maintenance_manager.cc:419] P c618ece1c943474792c85e90525898ca: Scheduling FlushDeltaMemStoresOp(11d467d20c4e433ca023ac0dd1a339fa): perf score=13.103000
I20260812 06:20:26.251892 14920 maintenance_manager.cc:643] P c618ece1c943474792c85e90525898ca: FlushDeltaMemStoresOp(11d467d20c4e433ca023ac0dd1a339fa) complete. Timing: real 0.051s	user 0.025s	sys 0.016s Metrics: {"bytes_written":14850989,"delete_count":0,"lbm_write_time_us":20028,"lbm_writes_lt_1ms":365,"reinsert_count":0,"update_count":1810}
I20260812 06:20:26.252522 14988 maintenance_manager.cc:419] P c618ece1c943474792c85e90525898ca: Scheduling FlushDeltaMemStoresOp(11d467d20c4e433ca023ac0dd1a339fa): perf score=1.000000
I20260812 06:20:26.262812 14920 maintenance_manager.cc:643] P c618ece1c943474792c85e90525898ca: FlushDeltaMemStoresOp(11d467d20c4e433ca023ac0dd1a339fa) complete. Timing: real 0.010s	user 0.005s	sys 0.000s Metrics: {"bytes_written":1969356,"delete_count":0,"lbm_write_time_us":1997,"lbm_writes_lt_1ms":51,"reinsert_count":0,"update_count":240}
I20260812 06:20:26.263222 14988 maintenance_manager.cc:419] P c618ece1c943474792c85e90525898ca: Scheduling FlushDeltaMemStoresOp(11d467d20c4e433ca023ac0dd1a339fa): perf score=2.188937
I20260812 06:20:26.272562 14920 maintenance_manager.cc:643] P c618ece1c943474792c85e90525898ca: FlushDeltaMemStoresOp(11d467d20c4e433ca023ac0dd1a339fa) complete. Timing: real 0.009s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3484,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:26.272995 14988 maintenance_manager.cc:419] P c618ece1c943474792c85e90525898ca: Scheduling MajorDeltaCompactionOp(11d467d20c4e433ca023ac0dd1a339fa): perf score=1.000000
I20260812 06:20:26.447712 14920 maintenance_manager.cc:643] P c618ece1c943474792c85e90525898ca: MajorDeltaCompactionOp(11d467d20c4e433ca023ac0dd1a339fa) complete. Timing: real 0.175s	user 0.134s	sys 0.040s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774751,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":462,"lbm_read_time_us":12573,"lbm_reads_lt_1ms":573,"lbm_write_time_us":29345,"lbm_writes_lt_1ms":543,"mutex_wait_us":31,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":71680,"update_count":2500}
I20260812 06:20:26.448242 14988 maintenance_manager.cc:419] P c618ece1c943474792c85e90525898ca: Scheduling FlushDeltaMemStoresOp(11d467d20c4e433ca023ac0dd1a339fa): perf score=14.095187
I20260812 06:20:26.511119 14920 maintenance_manager.cc:643] P c618ece1c943474792c85e90525898ca: FlushDeltaMemStoresOp(11d467d20c4e433ca023ac0dd1a339fa) complete. Timing: real 0.063s	user 0.021s	sys 0.024s Metrics: {"bytes_written":16409898,"delete_count":0,"lbm_write_time_us":21921,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:26.511736 14988 maintenance_manager.cc:419] P c618ece1c943474792c85e90525898ca: Scheduling FlushDeltaMemStoresOp(11d467d20c4e433ca023ac0dd1a339fa): perf score=2.188937
I20260812 06:20:26.522840 14920 maintenance_manager.cc:643] P c618ece1c943474792c85e90525898ca: FlushDeltaMemStoresOp(11d467d20c4e433ca023ac0dd1a339fa) complete. Timing: real 0.011s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4165,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:26.523430 14988 maintenance_manager.cc:419] P c618ece1c943474792c85e90525898ca: Scheduling MajorDeltaCompactionOp(11d467d20c4e433ca023ac0dd1a339fa): perf score=1.000000
I20260812 06:20:26.710630 14920 maintenance_manager.cc:643] P c618ece1c943474792c85e90525898ca: MajorDeltaCompactionOp(11d467d20c4e433ca023ac0dd1a339fa) complete. Timing: real 0.187s	user 0.132s	sys 0.050s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":212,"lbm_read_time_us":11548,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32903,"lbm_writes_lt_1ms":543,"mutex_wait_us":44,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11392,"update_count":2500}
I20260812 06:20:26.711315 14988 maintenance_manager.cc:419] P c618ece1c943474792c85e90525898ca: Scheduling FlushDeltaMemStoresOp(11d467d20c4e433ca023ac0dd1a339fa): perf score=14.095187
I20260812 06:20:26.779191 14920 maintenance_manager.cc:643] P c618ece1c943474792c85e90525898ca: FlushDeltaMemStoresOp(11d467d20c4e433ca023ac0dd1a339fa) complete. Timing: real 0.068s	user 0.024s	sys 0.031s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":22712,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:26.779757 14988 maintenance_manager.cc:419] P c618ece1c943474792c85e90525898ca: Scheduling FlushDeltaMemStoresOp(11d467d20c4e433ca023ac0dd1a339fa): perf score=2.188937
I20260812 06:20:26.790788 14920 maintenance_manager.cc:643] P c618ece1c943474792c85e90525898ca: FlushDeltaMemStoresOp(11d467d20c4e433ca023ac0dd1a339fa) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4278,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:26.791298 14988 maintenance_manager.cc:419] P c618ece1c943474792c85e90525898ca: Scheduling FlushMRSOp(11d467d20c4e433ca023ac0dd1a339fa): perf score=1.000000
I20260812 06:20:26.837713 14920 maintenance_manager.cc:643] P c618ece1c943474792c85e90525898ca: FlushMRSOp(11d467d20c4e433ca023ac0dd1a339fa) complete. Timing: real 0.046s	user 0.031s	sys 0.000s Metrics: {"bytes_written":1152510,"cfile_init":1,"dirs.queue_time_us":132,"dirs.run_cpu_time_us":255,"dirs.run_wall_time_us":1560,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1591,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:20:26.838480 14988 maintenance_manager.cc:419] P c618ece1c943474792c85e90525898ca: Scheduling LogGCOp(11d467d20c4e433ca023ac0dd1a339fa): free 112239564 bytes of WAL
I20260812 06:20:26.838758 14920 log_reader.cc:385] T 11d467d20c4e433ca023ac0dd1a339fa: removed 11 log segments from log reader
I20260812 06:20:26.838838 14920 log.cc:1079] T 11d467d20c4e433ca023ac0dd1a339fa P c618ece1c943474792c85e90525898ca: Deleting log segment in path: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616361105-14598-0/minicluster-data/ts-0-root/wals/11d467d20c4e433ca023ac0dd1a339fa/wal-000000027 (ops 129-133)
I20260812 06:20:26.838876 14920 log.cc:1079] T 11d467d20c4e433ca023ac0dd1a339fa P c618ece1c943474792c85e90525898ca: Deleting log segment in path: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616361105-14598-0/minicluster-data/ts-0-root/wals/11d467d20c4e433ca023ac0dd1a339fa/wal-000000028 (ops 134-138)
I20260812 06:20:26.838908 14920 log.cc:1079] T 11d467d20c4e433ca023ac0dd1a339fa P c618ece1c943474792c85e90525898ca: Deleting log segment in path: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616361105-14598-0/minicluster-data/ts-0-root/wals/11d467d20c4e433ca023ac0dd1a339fa/wal-000000029 (ops 139-143)
I20260812 06:20:26.838940 14920 log.cc:1079] T 11d467d20c4e433ca023ac0dd1a339fa P c618ece1c943474792c85e90525898ca: Deleting log segment in path: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616361105-14598-0/minicluster-data/ts-0-root/wals/11d467d20c4e433ca023ac0dd1a339fa/wal-000000030 (ops 144-148)
I20260812 06:20:26.838967 14920 log.cc:1079] T 11d467d20c4e433ca023ac0dd1a339fa P c618ece1c943474792c85e90525898ca: Deleting log segment in path: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616361105-14598-0/minicluster-data/ts-0-root/wals/11d467d20c4e433ca023ac0dd1a339fa/wal-000000031 (ops 149-153)
I20260812 06:20:26.839000 14920 log.cc:1079] T 11d467d20c4e433ca023ac0dd1a339fa P c618ece1c943474792c85e90525898ca: Deleting log segment in path: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616361105-14598-0/minicluster-data/ts-0-root/wals/11d467d20c4e433ca023ac0dd1a339fa/wal-000000032 (ops 154-158)
I20260812 06:20:26.839030 14920 log.cc:1079] T 11d467d20c4e433ca023ac0dd1a339fa P c618ece1c943474792c85e90525898ca: Deleting log segment in path: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616361105-14598-0/minicluster-data/ts-0-root/wals/11d467d20c4e433ca023ac0dd1a339fa/wal-000000033 (ops 159-163)
I20260812 06:20:26.839057 14920 log.cc:1079] T 11d467d20c4e433ca023ac0dd1a339fa P c618ece1c943474792c85e90525898ca: Deleting log segment in path: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616361105-14598-0/minicluster-data/ts-0-root/wals/11d467d20c4e433ca023ac0dd1a339fa/wal-000000034 (ops 164-168)
I20260812 06:20:26.839087 14920 log.cc:1079] T 11d467d20c4e433ca023ac0dd1a339fa P c618ece1c943474792c85e90525898ca: Deleting log segment in path: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616361105-14598-0/minicluster-data/ts-0-root/wals/11d467d20c4e433ca023ac0dd1a339fa/wal-000000035 (ops 169-172)
I20260812 06:20:26.839118 14920 log.cc:1079] T 11d467d20c4e433ca023ac0dd1a339fa P c618ece1c943474792c85e90525898ca: Deleting log segment in path: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616361105-14598-0/minicluster-data/ts-0-root/wals/11d467d20c4e433ca023ac0dd1a339fa/wal-000000036 (ops 173-177)
I20260812 06:20:26.839152 14920 log.cc:1079] T 11d467d20c4e433ca023ac0dd1a339fa P c618ece1c943474792c85e90525898ca: Deleting log segment in path: /tmp/dist-test-taskK8Nxju/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515616361105-14598-0/minicluster-data/ts-0-root/wals/11d467d20c4e433ca023ac0dd1a339fa/wal-000000037 (ops 178-182)
I20260812 06:20:26.865981 14920 maintenance_manager.cc:643] P c618ece1c943474792c85e90525898ca: LogGCOp(11d467d20c4e433ca023ac0dd1a339fa) complete. Timing: real 0.027s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:20:26.866493 14988 maintenance_manager.cc:419] P c618ece1c943474792c85e90525898ca: Scheduling UndoDeltaBlockGCOp(11d467d20c4e433ca023ac0dd1a339fa): 448 bytes on disk
I20260812 06:20:26.867069 14920 maintenance_manager.cc:643] P c618ece1c943474792c85e90525898ca: UndoDeltaBlockGCOp(11d467d20c4e433ca023ac0dd1a339fa) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":80,"lbm_reads_lt_1ms":4}
I20260812 06:20:26.867673 14988 maintenance_manager.cc:419] P c618ece1c943474792c85e90525898ca: Scheduling FlushDeltaMemStoresOp(11d467d20c4e433ca023ac0dd1a339fa): perf score=2.188937
I20260812 06:20:26.893620 14920 maintenance_manager.cc:643] P c618ece1c943474792c85e90525898ca: FlushDeltaMemStoresOp(11d467d20c4e433ca023ac0dd1a339fa) complete. Timing: real 0.026s	user 0.007s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5872,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:26.894085 14988 maintenance_manager.cc:419] P c618ece1c943474792c85e90525898ca: Scheduling FlushDeltaMemStoresOp(11d467d20c4e433ca023ac0dd1a339fa): perf score=2.188937
I20260812 06:20:26.904430 14920 maintenance_manager.cc:643] P c618ece1c943474792c85e90525898ca: FlushDeltaMemStoresOp(11d467d20c4e433ca023ac0dd1a339fa) complete. Timing: real 0.010s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3915,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:26.904915 14988 maintenance_manager.cc:419] P c618ece1c943474792c85e90525898ca: Scheduling MajorDeltaCompactionOp(11d467d20c4e433ca023ac0dd1a339fa): perf score=1.000000
I20260812 06:20:27.146363 14920 maintenance_manager.cc:643] P c618ece1c943474792c85e90525898ca: MajorDeltaCompactionOp(11d467d20c4e433ca023ac0dd1a339fa) complete. Timing: real 0.241s	user 0.164s	sys 0.063s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979754,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":2094,"lbm_read_time_us":17013,"lbm_reads_lt_1ms":774,"lbm_write_time_us":39773,"lbm_writes_lt_1ms":743,"mutex_wait_us":39,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":14976,"thread_start_us":82,"threads_started":1,"update_count":3500}
I20260812 06:20:27.147147 14988 maintenance_manager.cc:419] P c618ece1c943474792c85e90525898ca: Scheduling FlushDeltaMemStoresOp(11d467d20c4e433ca023ac0dd1a339fa): perf score=18.063937
I20260812 06:20:27.202551 14920 maintenance_manager.cc:643] P c618ece1c943474792c85e90525898ca: FlushDeltaMemStoresOp(11d467d20c4e433ca023ac0dd1a339fa) complete. Timing: real 0.055s	user 0.032s	sys 0.021s Metrics: {"bytes_written":20512318,"delete_count":0,"lbm_write_time_us":25449,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:27.203159 14988 maintenance_manager.cc:419] P c618ece1c943474792c85e90525898ca: Scheduling FlushDeltaMemStoresOp(11d467d20c4e433ca023ac0dd1a339fa): perf score=2.188937
I20260812 06:20:27.216888 14920 maintenance_manager.cc:643] P c618ece1c943474792c85e90525898ca: FlushDeltaMemStoresOp(11d467d20c4e433ca023ac0dd1a339fa) complete. Timing: real 0.014s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5357,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:27.217407 14988 maintenance_manager.cc:419] P c618ece1c943474792c85e90525898ca: Scheduling MajorDeltaCompactionOp(11d467d20c4e433ca023ac0dd1a339fa): perf score=1.000000
I20260812 06:20:27.239910 14598 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.031s	user 1.796s	sys 0.214s
I20260812 06:20:27.294121 14598 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.054s	user 0.001s	sys 0.000s
I20260812 06:20:27.294631 14598 tablet_server.cc:179] TabletServer@127.14.65.129:0 shutting down...
I20260812 06:20:27.374527 14920 maintenance_manager.cc:643] P c618ece1c943474792c85e90525898ca: MajorDeltaCompactionOp(11d467d20c4e433ca023ac0dd1a339fa) complete. Timing: real 0.157s	user 0.104s	sys 0.053s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877104,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":339,"lbm_read_time_us":13978,"lbm_reads_lt_1ms":668,"lbm_write_time_us":30180,"lbm_writes_lt_1ms":643,"mutex_wait_us":29,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":15616,"update_count":3000}
I20260812 06:20:27.375367 14598 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:27.375705 14598 tablet_replica.cc:333] T 11d467d20c4e433ca023ac0dd1a339fa P c618ece1c943474792c85e90525898ca: stopping tablet replica
I20260812 06:20:27.375862 14598 raft_consensus.cc:2243] T 11d467d20c4e433ca023ac0dd1a339fa P c618ece1c943474792c85e90525898ca [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:27.376113 14598 raft_consensus.cc:2272] T 11d467d20c4e433ca023ac0dd1a339fa P c618ece1c943474792c85e90525898ca [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:27.380955 14598 tablet_server.cc:196] TabletServer@127.14.65.129:0 shutdown complete.
I20260812 06:20:27.429068 14598 master.cc:562] Master@127.14.65.190:39799 shutting down...
I20260812 06:20:27.432824 14598 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 580a560ffed849d89f3b09aba3eb0ef4 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:27.433027 14598 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 580a560ffed849d89f3b09aba3eb0ef4 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:27.433082 14598 tablet_replica.cc:333] T 00000000000000000000000000000000 P 580a560ffed849d89f3b09aba3eb0ef4: stopping tablet replica
I20260812 06:20:27.445827 14598 master.cc:584] Master@127.14.65.190:39799 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5573 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11165 ms total)

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