[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:18:22.541177   810 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.0.202.190:35327
I20260812 06:18:22.542145   810 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:18:22.542798   810 file_cache.cc:504] Constructed file cache file cache with capacity 419430
I20260812 06:18:22.548695   810 server_base.cc:1061] running on GCE node
W20260812 06:18:22.548645   817 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:22.548650   819 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:22.548914   821 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:22.549371   810 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:22.549456   810 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:22.549546   810 hybrid_clock.cc:648] HybridClock initialized: now 1786515502549544 us; error 0 us; skew 500 ppm
I20260812 06:18:22.555311   810 webserver.cc:533] Webserver started at http://127.0.202.190:45509/ using document root <none> and password file <none>
I20260812 06:18:22.555790   810 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:22.555843   810 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:22.556016   810 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:22.557531   810 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502530812-810-0/minicluster-data/master-0-root/instance:
uuid: "6448a8f25c12406d9035a6d5a5f61ed4"
format_stamp: "Formatted at 2026-08-12 06:18:22 on dist-test-slave-gp6n"
I20260812 06:18:22.560931   810 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.001s	sys 0.004s
I20260812 06:18:22.562855   827 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:22.563864   810 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:22.564030   810 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502530812-810-0/minicluster-data/master-0-root
uuid: "6448a8f25c12406d9035a6d5a5f61ed4"
format_stamp: "Formatted at 2026-08-12 06:18:22 on dist-test-slave-gp6n"
I20260812 06:18:22.564144   810 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502530812-810-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502530812-810-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502530812-810-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:22.587280   810 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:22.587878   810 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:18:22.588056   810 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:22.595844   810 rpc_server.cc:307] RPC server started. Bound to: 127.0.202.190:35327
I20260812 06:18:22.595849   884 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.0.202.190:35327 every 8 connection(s)
I20260812 06:18:22.598052   886 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:22.603096   886 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 6448a8f25c12406d9035a6d5a5f61ed4: Bootstrap starting.
I20260812 06:18:22.605223   886 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 6448a8f25c12406d9035a6d5a5f61ed4: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:22.606014   886 log.cc:826] T 00000000000000000000000000000000 P 6448a8f25c12406d9035a6d5a5f61ed4: Log is configured to *not* fsync() on all Append() calls
I20260812 06:18:22.607497   886 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 6448a8f25c12406d9035a6d5a5f61ed4: No bootstrap required, opened a new log
I20260812 06:18:22.610046   886 raft_consensus.cc:359] T 00000000000000000000000000000000 P 6448a8f25c12406d9035a6d5a5f61ed4 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6448a8f25c12406d9035a6d5a5f61ed4" member_type: VOTER }
I20260812 06:18:22.610195   886 raft_consensus.cc:385] T 00000000000000000000000000000000 P 6448a8f25c12406d9035a6d5a5f61ed4 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:22.610234   886 raft_consensus.cc:740] T 00000000000000000000000000000000 P 6448a8f25c12406d9035a6d5a5f61ed4 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 6448a8f25c12406d9035a6d5a5f61ed4, State: Initialized, Role: FOLLOWER
I20260812 06:18:22.610807   886 consensus_queue.cc:260] T 00000000000000000000000000000000 P 6448a8f25c12406d9035a6d5a5f61ed4 [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: "6448a8f25c12406d9035a6d5a5f61ed4" member_type: VOTER }
I20260812 06:18:22.610939   886 raft_consensus.cc:399] T 00000000000000000000000000000000 P 6448a8f25c12406d9035a6d5a5f61ed4 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:22.610980   886 raft_consensus.cc:493] T 00000000000000000000000000000000 P 6448a8f25c12406d9035a6d5a5f61ed4 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:22.611071   886 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 6448a8f25c12406d9035a6d5a5f61ed4 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:22.611733   886 raft_consensus.cc:515] T 00000000000000000000000000000000 P 6448a8f25c12406d9035a6d5a5f61ed4 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6448a8f25c12406d9035a6d5a5f61ed4" member_type: VOTER }
I20260812 06:18:22.612087   886 leader_election.cc:304] T 00000000000000000000000000000000 P 6448a8f25c12406d9035a6d5a5f61ed4 [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: 6448a8f25c12406d9035a6d5a5f61ed4; no voters: 
I20260812 06:18:22.612330   886 leader_election.cc:290] T 00000000000000000000000000000000 P 6448a8f25c12406d9035a6d5a5f61ed4 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:22.612468   890 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 6448a8f25c12406d9035a6d5a5f61ed4 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:22.612728   890 raft_consensus.cc:697] T 00000000000000000000000000000000 P 6448a8f25c12406d9035a6d5a5f61ed4 [term 1 LEADER]: Becoming Leader. State: Replica: 6448a8f25c12406d9035a6d5a5f61ed4, State: Running, Role: LEADER
I20260812 06:18:22.613134   890 consensus_queue.cc:237] T 00000000000000000000000000000000 P 6448a8f25c12406d9035a6d5a5f61ed4 [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: "6448a8f25c12406d9035a6d5a5f61ed4" member_type: VOTER }
I20260812 06:18:22.613346   886 sys_catalog.cc:565] T 00000000000000000000000000000000 P 6448a8f25c12406d9035a6d5a5f61ed4 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:22.615072   891 sys_catalog.cc:455] T 00000000000000000000000000000000 P 6448a8f25c12406d9035a6d5a5f61ed4 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "6448a8f25c12406d9035a6d5a5f61ed4" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6448a8f25c12406d9035a6d5a5f61ed4" member_type: VOTER } }
I20260812 06:18:22.615060   892 sys_catalog.cc:455] T 00000000000000000000000000000000 P 6448a8f25c12406d9035a6d5a5f61ed4 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 6448a8f25c12406d9035a6d5a5f61ed4. Latest consensus state: current_term: 1 leader_uuid: "6448a8f25c12406d9035a6d5a5f61ed4" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6448a8f25c12406d9035a6d5a5f61ed4" member_type: VOTER } }
I20260812 06:18:22.615294   892 sys_catalog.cc:458] T 00000000000000000000000000000000 P 6448a8f25c12406d9035a6d5a5f61ed4 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:22.615294   891 sys_catalog.cc:458] T 00000000000000000000000000000000 P 6448a8f25c12406d9035a6d5a5f61ed4 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:22.615514   810 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
W20260812 06:18:22.617328   910 catalog_manager.cc:1594] T 00000000000000000000000000000000 P 6448a8f25c12406d9035a6d5a5f61ed4: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:18:22.617390   910 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:18:22.617467   909 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:22.618183   909 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:22.622658   909 catalog_manager.cc:1383] Generated new cluster ID: e0654949455a46e7bec01187215f6e9e
I20260812 06:18:22.622717   909 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:22.635005   909 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:22.636039   909 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:22.646960   909 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 6448a8f25c12406d9035a6d5a5f61ed4: Generated new TSK 0
I20260812 06:18:22.647639   909 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:22.680327   810 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:22.683367   915 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:22.683723   916 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:22.684243   919 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:22.684329   810 server_base.cc:1061] running on GCE node
I20260812 06:18:22.684587   810 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:22.684631   810 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:22.684654   810 hybrid_clock.cc:648] HybridClock initialized: now 1786515502684654 us; error 0 us; skew 500 ppm
I20260812 06:18:22.685592   810 webserver.cc:533] Webserver started at http://127.0.202.129:38213/ using document root <none> and password file <none>
I20260812 06:18:22.685811   810 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:22.685910   810 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:22.686036   810 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:22.686561   810 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502530812-810-0/minicluster-data/ts-0-root/instance:
uuid: "751ad1762ccf4a819ab73286727685e9"
format_stamp: "Formatted at 2026-08-12 06:18:22 on dist-test-slave-gp6n"
I20260812 06:18:22.688485   810 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:22.689616   924 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:22.689879   810 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:22.689983   810 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502530812-810-0/minicluster-data/ts-0-root
uuid: "751ad1762ccf4a819ab73286727685e9"
format_stamp: "Formatted at 2026-08-12 06:18:22 on dist-test-slave-gp6n"
I20260812 06:18:22.690104   810 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502530812-810-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502530812-810-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502530812-810-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:22.713817   810 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:22.714367   810 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:22.715116   810 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:22.716010   810 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:22.716099   810 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:22.716176   810 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:22.716207   810 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:22.723063   810 rpc_server.cc:307] RPC server started. Bound to: 127.0.202.129:36547
I20260812 06:18:22.723090  1004 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.0.202.129:36547 every 8 connection(s)
I20260812 06:18:22.733449  1005 heartbeater.cc:344] Connected to a master server at 127.0.202.190:35327
I20260812 06:18:22.733693  1005 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:22.734123  1005 heartbeater.cc:507] Master 127.0.202.190:35327 requested a full tablet report, sending...
I20260812 06:18:22.735517   845 ts_manager.cc:194] Registered new tserver with Master: 751ad1762ccf4a819ab73286727685e9 (127.0.202.129:36547)
I20260812 06:18:22.736040   810 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.012306617s
I20260812 06:18:22.736755   845 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:58332
I20260812 06:18:22.745355   845 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:58344:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:18:22.759006   962 tablet_service.cc:1511] Processing CreateTablet for tablet a31ccba795fe4388bb67548bb4960c1f (DEFAULT_TABLE table=heavy-update-compaction-test [id=2ef8468839a54feaa93cf9d1f070274d]), partition=
I20260812 06:18:22.759492   962 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet a31ccba795fe4388bb67548bb4960c1f. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:22.761682  1020 tablet_bootstrap.cc:492] T a31ccba795fe4388bb67548bb4960c1f P 751ad1762ccf4a819ab73286727685e9: Bootstrap starting.
I20260812 06:18:22.762794  1020 tablet_bootstrap.cc:654] T a31ccba795fe4388bb67548bb4960c1f P 751ad1762ccf4a819ab73286727685e9: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:22.763896  1020 tablet_bootstrap.cc:492] T a31ccba795fe4388bb67548bb4960c1f P 751ad1762ccf4a819ab73286727685e9: No bootstrap required, opened a new log
I20260812 06:18:22.764034  1020 ts_tablet_manager.cc:1403] T a31ccba795fe4388bb67548bb4960c1f P 751ad1762ccf4a819ab73286727685e9: Time spent bootstrapping tablet: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:18:22.764479  1020 raft_consensus.cc:359] T a31ccba795fe4388bb67548bb4960c1f P 751ad1762ccf4a819ab73286727685e9 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "751ad1762ccf4a819ab73286727685e9" member_type: VOTER last_known_addr { host: "127.0.202.129" port: 36547 } }
I20260812 06:18:22.764575  1020 raft_consensus.cc:385] T a31ccba795fe4388bb67548bb4960c1f P 751ad1762ccf4a819ab73286727685e9 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:22.764598  1020 raft_consensus.cc:740] T a31ccba795fe4388bb67548bb4960c1f P 751ad1762ccf4a819ab73286727685e9 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 751ad1762ccf4a819ab73286727685e9, State: Initialized, Role: FOLLOWER
I20260812 06:18:22.764765  1020 consensus_queue.cc:260] T a31ccba795fe4388bb67548bb4960c1f P 751ad1762ccf4a819ab73286727685e9 [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: "751ad1762ccf4a819ab73286727685e9" member_type: VOTER last_known_addr { host: "127.0.202.129" port: 36547 } }
I20260812 06:18:22.764834  1020 raft_consensus.cc:399] T a31ccba795fe4388bb67548bb4960c1f P 751ad1762ccf4a819ab73286727685e9 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:22.764880  1020 raft_consensus.cc:493] T a31ccba795fe4388bb67548bb4960c1f P 751ad1762ccf4a819ab73286727685e9 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:22.764933  1020 raft_consensus.cc:3060] T a31ccba795fe4388bb67548bb4960c1f P 751ad1762ccf4a819ab73286727685e9 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:22.765618  1020 raft_consensus.cc:515] T a31ccba795fe4388bb67548bb4960c1f P 751ad1762ccf4a819ab73286727685e9 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "751ad1762ccf4a819ab73286727685e9" member_type: VOTER last_known_addr { host: "127.0.202.129" port: 36547 } }
I20260812 06:18:22.765753  1020 leader_election.cc:304] T a31ccba795fe4388bb67548bb4960c1f P 751ad1762ccf4a819ab73286727685e9 [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: 751ad1762ccf4a819ab73286727685e9; no voters: 
I20260812 06:18:22.765993  1020 leader_election.cc:290] T a31ccba795fe4388bb67548bb4960c1f P 751ad1762ccf4a819ab73286727685e9 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:22.766242  1023 raft_consensus.cc:2804] T a31ccba795fe4388bb67548bb4960c1f P 751ad1762ccf4a819ab73286727685e9 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:22.766522  1020 ts_tablet_manager.cc:1434] T a31ccba795fe4388bb67548bb4960c1f P 751ad1762ccf4a819ab73286727685e9: Time spent starting tablet: real 0.002s	user 0.000s	sys 0.003s
I20260812 06:18:22.766505  1023 raft_consensus.cc:697] T a31ccba795fe4388bb67548bb4960c1f P 751ad1762ccf4a819ab73286727685e9 [term 1 LEADER]: Becoming Leader. State: Replica: 751ad1762ccf4a819ab73286727685e9, State: Running, Role: LEADER
I20260812 06:18:22.766935  1005 heartbeater.cc:499] Master 127.0.202.190:35327 was elected leader, sending a full tablet report...
I20260812 06:18:22.766932  1023 consensus_queue.cc:237] T a31ccba795fe4388bb67548bb4960c1f P 751ad1762ccf4a819ab73286727685e9 [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: "751ad1762ccf4a819ab73286727685e9" member_type: VOTER last_known_addr { host: "127.0.202.129" port: 36547 } }
I20260812 06:18:22.769654   845 catalog_manager.cc:5719] T a31ccba795fe4388bb67548bb4960c1f P 751ad1762ccf4a819ab73286727685e9 reported cstate change: term changed from 0 to 1, leader changed from <none> to 751ad1762ccf4a819ab73286727685e9 (127.0.202.129). New cstate: current_term: 1 leader_uuid: "751ad1762ccf4a819ab73286727685e9" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "751ad1762ccf4a819ab73286727685e9" member_type: VOTER last_known_addr { host: "127.0.202.129" port: 36547 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:22.835649   810 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.056s	user 0.021s	sys 0.005s
I20260812 06:18:22.974432  1006 maintenance_manager.cc:419] P 751ad1762ccf4a819ab73286727685e9: Scheduling FlushMRSOp(a31ccba795fe4388bb67548bb4960c1f): perf score=19.054940
I20260812 06:18:23.178371   931 maintenance_manager.cc:643] P 751ad1762ccf4a819ab73286727685e9: FlushMRSOp(a31ccba795fe4388bb67548bb4960c1f) complete. Timing: real 0.204s	user 0.154s	sys 0.036s Metrics: {"bytes_written":14440742,"cfile_init":1,"compiler_manager_pool.queue_time_us":220,"delete_count":0,"dirs.queue_time_us":93,"dirs.run_cpu_time_us":246,"dirs.run_wall_time_us":906,"drs_written":1,"lbm_read_time_us":73,"lbm_reads_lt_1ms":4,"lbm_write_time_us":48307,"lbm_writes_lt_1ms":809,"mutex_wait_us":223,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":149248,"thread_start_us":143,"threads_started":1,"update_count":1760}
I20260812 06:18:23.179580  1006 maintenance_manager.cc:419] P 751ad1762ccf4a819ab73286727685e9: Scheduling LogGCOp(a31ccba795fe4388bb67548bb4960c1f): free 20743880 bytes of WAL
I20260812 06:18:23.179914   931 log_reader.cc:385] T a31ccba795fe4388bb67548bb4960c1f: removed 2 log segments from log reader
I20260812 06:18:23.179996   931 log.cc:1079] T a31ccba795fe4388bb67548bb4960c1f P 751ad1762ccf4a819ab73286727685e9: Deleting log segment in path: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502530812-810-0/minicluster-data/ts-0-root/wals/a31ccba795fe4388bb67548bb4960c1f/wal-000000001 (ops 1-6)
I20260812 06:18:23.180068   931 log.cc:1079] T a31ccba795fe4388bb67548bb4960c1f P 751ad1762ccf4a819ab73286727685e9: Deleting log segment in path: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502530812-810-0/minicluster-data/ts-0-root/wals/a31ccba795fe4388bb67548bb4960c1f/wal-000000002 (ops 7-11)
I20260812 06:18:23.184373   931 maintenance_manager.cc:643] P 751ad1762ccf4a819ab73286727685e9: LogGCOp(a31ccba795fe4388bb67548bb4960c1f) complete. Timing: real 0.005s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:18:23.184749  1006 maintenance_manager.cc:419] P 751ad1762ccf4a819ab73286727685e9: Scheduling FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f): perf score=4.173312
I20260812 06:18:23.200857   931 maintenance_manager.cc:643] P 751ad1762ccf4a819ab73286727685e9: FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f) complete. Timing: real 0.016s	user 0.009s	sys 0.004s Metrics: {"bytes_written":6071828,"delete_count":0,"lbm_write_time_us":6157,"lbm_writes_lt_1ms":151,"reinsert_count":0,"update_count":740}
I20260812 06:18:23.201445  1006 maintenance_manager.cc:419] P 751ad1762ccf4a819ab73286727685e9: Scheduling MajorDeltaCompactionOp(a31ccba795fe4388bb67548bb4960c1f): perf score=1.000000
I20260812 06:18:23.386861   931 maintenance_manager.cc:643] P 751ad1762ccf4a819ab73286727685e9: MajorDeltaCompactionOp(a31ccba795fe4388bb67548bb4960c1f) complete. Timing: real 0.185s	user 0.122s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774692,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":815,"lbm_read_time_us":11931,"lbm_reads_lt_1ms":568,"lbm_write_time_us":28919,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"thread_start_us":293,"threads_started":5,"update_count":2500}
I20260812 06:18:23.387403  1006 maintenance_manager.cc:419] P 751ad1762ccf4a819ab73286727685e9: Scheduling FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f): perf score=14.095187
I20260812 06:18:23.438047   931 maintenance_manager.cc:643] P 751ad1762ccf4a819ab73286727685e9: FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f) complete. Timing: real 0.050s	user 0.032s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20709,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:23.438591  1006 maintenance_manager.cc:419] P 751ad1762ccf4a819ab73286727685e9: Scheduling FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f): perf score=2.188937
I20260812 06:18:23.449307   931 maintenance_manager.cc:643] P 751ad1762ccf4a819ab73286727685e9: FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f) complete. Timing: real 0.011s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3905,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:23.449841  1006 maintenance_manager.cc:419] P 751ad1762ccf4a819ab73286727685e9: Scheduling UndoDeltaBlockGCOp(a31ccba795fe4388bb67548bb4960c1f): 16411396 bytes on disk
I20260812 06:18:23.450593   931 maintenance_manager.cc:643] P 751ad1762ccf4a819ab73286727685e9: UndoDeltaBlockGCOp(a31ccba795fe4388bb67548bb4960c1f) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":85,"lbm_reads_lt_1ms":4}
I20260812 06:18:23.451097  1006 maintenance_manager.cc:419] P 751ad1762ccf4a819ab73286727685e9: Scheduling MajorDeltaCompactionOp(a31ccba795fe4388bb67548bb4960c1f): perf score=1.000000
I20260812 06:18:23.639145   931 maintenance_manager.cc:643] P 751ad1762ccf4a819ab73286727685e9: MajorDeltaCompactionOp(a31ccba795fe4388bb67548bb4960c1f) complete. Timing: real 0.188s	user 0.123s	sys 0.051s 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":965,"lbm_read_time_us":12116,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28034,"lbm_writes_lt_1ms":543,"mutex_wait_us":272,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7936,"update_count":2500}
I20260812 06:18:23.639792  1006 maintenance_manager.cc:419] P 751ad1762ccf4a819ab73286727685e9: Scheduling FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f): perf score=14.095187
I20260812 06:18:23.692305   931 maintenance_manager.cc:643] P 751ad1762ccf4a819ab73286727685e9: FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f) complete. Timing: real 0.052s	user 0.034s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24915,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:23.692785  1006 maintenance_manager.cc:419] P 751ad1762ccf4a819ab73286727685e9: Scheduling FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f): perf score=2.188937
I20260812 06:18:23.704105   931 maintenance_manager.cc:643] P 751ad1762ccf4a819ab73286727685e9: FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f) complete. Timing: real 0.011s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4399,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:23.704584  1006 maintenance_manager.cc:419] P 751ad1762ccf4a819ab73286727685e9: Scheduling MajorDeltaCompactionOp(a31ccba795fe4388bb67548bb4960c1f): perf score=1.000000
I20260812 06:18:23.863474   931 maintenance_manager.cc:643] P 751ad1762ccf4a819ab73286727685e9: MajorDeltaCompactionOp(a31ccba795fe4388bb67548bb4960c1f) complete. Timing: real 0.159s	user 0.122s	sys 0.032s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1373,"lbm_read_time_us":9979,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30951,"lbm_writes_lt_1ms":543,"mutex_wait_us":518,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:18:23.864149  1006 maintenance_manager.cc:419] P 751ad1762ccf4a819ab73286727685e9: Scheduling FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f): perf score=11.118625
I20260812 06:18:23.913156   931 maintenance_manager.cc:643] P 751ad1762ccf4a819ab73286727685e9: FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f) complete. Timing: real 0.049s	user 0.036s	sys 0.008s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":20710,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":1550}
I20260812 06:18:23.913651  1006 maintenance_manager.cc:419] P 751ad1762ccf4a819ab73286727685e9: Scheduling FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f): perf score=2.188937
I20260812 06:18:23.924806   931 maintenance_manager.cc:643] P 751ad1762ccf4a819ab73286727685e9: FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3951,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:23.925273  1006 maintenance_manager.cc:419] P 751ad1762ccf4a819ab73286727685e9: Scheduling FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f): perf score=2.188937
I20260812 06:18:23.934655   931 maintenance_manager.cc:643] P 751ad1762ccf4a819ab73286727685e9: FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f) complete. Timing: real 0.009s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3526,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:23.935055  1006 maintenance_manager.cc:419] P 751ad1762ccf4a819ab73286727685e9: Scheduling MajorDeltaCompactionOp(a31ccba795fe4388bb67548bb4960c1f): perf score=1.000000
I20260812 06:18:24.093127   931 maintenance_manager.cc:643] P 751ad1762ccf4a819ab73286727685e9: MajorDeltaCompactionOp(a31ccba795fe4388bb67548bb4960c1f) complete. Timing: real 0.158s	user 0.121s	sys 0.023s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774798,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":256,"lbm_read_time_us":10007,"lbm_reads_lt_1ms":573,"lbm_write_time_us":30575,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3072,"update_count":2500}
I20260812 06:18:24.093694  1006 maintenance_manager.cc:419] P 751ad1762ccf4a819ab73286727685e9: Scheduling FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f): perf score=14.095187
I20260812 06:18:24.144073   931 maintenance_manager.cc:643] P 751ad1762ccf4a819ab73286727685e9: FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f) complete. Timing: real 0.050s	user 0.028s	sys 0.020s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20543,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:24.144559  1006 maintenance_manager.cc:419] P 751ad1762ccf4a819ab73286727685e9: Scheduling FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f): perf score=2.188937
I20260812 06:18:24.154963   931 maintenance_manager.cc:643] P 751ad1762ccf4a819ab73286727685e9: FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3854,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:24.155557  1006 maintenance_manager.cc:419] P 751ad1762ccf4a819ab73286727685e9: Scheduling MajorDeltaCompactionOp(a31ccba795fe4388bb67548bb4960c1f): perf score=1.000000
I20260812 06:18:24.308818   931 maintenance_manager.cc:643] P 751ad1762ccf4a819ab73286727685e9: MajorDeltaCompactionOp(a31ccba795fe4388bb67548bb4960c1f) complete. Timing: real 0.153s	user 0.111s	sys 0.032s 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":158,"lbm_read_time_us":9711,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29931,"lbm_writes_lt_1ms":543,"mutex_wait_us":38,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2500}
I20260812 06:18:24.309581  1006 maintenance_manager.cc:419] P 751ad1762ccf4a819ab73286727685e9: Scheduling FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f): perf score=14.095187
I20260812 06:18:24.358049   931 maintenance_manager.cc:643] P 751ad1762ccf4a819ab73286727685e9: FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f) complete. Timing: real 0.048s	user 0.022s	sys 0.015s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18567,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:24.358582  1006 maintenance_manager.cc:419] P 751ad1762ccf4a819ab73286727685e9: Scheduling FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f): perf score=2.188937
I20260812 06:18:24.369912   931 maintenance_manager.cc:643] P 751ad1762ccf4a819ab73286727685e9: FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4059,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:24.370492  1006 maintenance_manager.cc:419] P 751ad1762ccf4a819ab73286727685e9: Scheduling FlushMRSOp(a31ccba795fe4388bb67548bb4960c1f): perf score=1.000000
I20260812 06:18:24.400350   931 maintenance_manager.cc:643] P 751ad1762ccf4a819ab73286727685e9: FlushMRSOp(a31ccba795fe4388bb67548bb4960c1f) complete. Timing: real 0.030s	user 0.028s	sys 0.000s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":77,"dirs.run_cpu_time_us":215,"dirs.run_wall_time_us":1528,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1437,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:18:24.401155  1006 maintenance_manager.cc:419] P 751ad1762ccf4a819ab73286727685e9: Scheduling LogGCOp(a31ccba795fe4388bb67548bb4960c1f): free 124257261 bytes of WAL
I20260812 06:18:24.401429   931 log_reader.cc:385] T a31ccba795fe4388bb67548bb4960c1f: removed 12 log segments from log reader
I20260812 06:18:24.401502   931 log.cc:1079] T a31ccba795fe4388bb67548bb4960c1f P 751ad1762ccf4a819ab73286727685e9: Deleting log segment in path: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502530812-810-0/minicluster-data/ts-0-root/wals/a31ccba795fe4388bb67548bb4960c1f/wal-000000003 (ops 12-16)
I20260812 06:18:24.401541   931 log.cc:1079] T a31ccba795fe4388bb67548bb4960c1f P 751ad1762ccf4a819ab73286727685e9: Deleting log segment in path: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502530812-810-0/minicluster-data/ts-0-root/wals/a31ccba795fe4388bb67548bb4960c1f/wal-000000004 (ops 17-21)
I20260812 06:18:24.401564   931 log.cc:1079] T a31ccba795fe4388bb67548bb4960c1f P 751ad1762ccf4a819ab73286727685e9: Deleting log segment in path: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502530812-810-0/minicluster-data/ts-0-root/wals/a31ccba795fe4388bb67548bb4960c1f/wal-000000005 (ops 22-26)
I20260812 06:18:24.401602   931 log.cc:1079] T a31ccba795fe4388bb67548bb4960c1f P 751ad1762ccf4a819ab73286727685e9: Deleting log segment in path: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502530812-810-0/minicluster-data/ts-0-root/wals/a31ccba795fe4388bb67548bb4960c1f/wal-000000006 (ops 27-30)
I20260812 06:18:24.401628   931 log.cc:1079] T a31ccba795fe4388bb67548bb4960c1f P 751ad1762ccf4a819ab73286727685e9: Deleting log segment in path: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502530812-810-0/minicluster-data/ts-0-root/wals/a31ccba795fe4388bb67548bb4960c1f/wal-000000007 (ops 31-35)
I20260812 06:18:24.401650   931 log.cc:1079] T a31ccba795fe4388bb67548bb4960c1f P 751ad1762ccf4a819ab73286727685e9: Deleting log segment in path: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502530812-810-0/minicluster-data/ts-0-root/wals/a31ccba795fe4388bb67548bb4960c1f/wal-000000008 (ops 36-40)
I20260812 06:18:24.401678   931 log.cc:1079] T a31ccba795fe4388bb67548bb4960c1f P 751ad1762ccf4a819ab73286727685e9: Deleting log segment in path: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502530812-810-0/minicluster-data/ts-0-root/wals/a31ccba795fe4388bb67548bb4960c1f/wal-000000009 (ops 41-45)
I20260812 06:18:24.401705   931 log.cc:1079] T a31ccba795fe4388bb67548bb4960c1f P 751ad1762ccf4a819ab73286727685e9: Deleting log segment in path: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502530812-810-0/minicluster-data/ts-0-root/wals/a31ccba795fe4388bb67548bb4960c1f/wal-000000010 (ops 46-50)
I20260812 06:18:24.401734   931 log.cc:1079] T a31ccba795fe4388bb67548bb4960c1f P 751ad1762ccf4a819ab73286727685e9: Deleting log segment in path: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502530812-810-0/minicluster-data/ts-0-root/wals/a31ccba795fe4388bb67548bb4960c1f/wal-000000011 (ops 51-55)
I20260812 06:18:24.401768   931 log.cc:1079] T a31ccba795fe4388bb67548bb4960c1f P 751ad1762ccf4a819ab73286727685e9: Deleting log segment in path: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502530812-810-0/minicluster-data/ts-0-root/wals/a31ccba795fe4388bb67548bb4960c1f/wal-000000012 (ops 56-60)
I20260812 06:18:24.401803   931 log.cc:1079] T a31ccba795fe4388bb67548bb4960c1f P 751ad1762ccf4a819ab73286727685e9: Deleting log segment in path: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502530812-810-0/minicluster-data/ts-0-root/wals/a31ccba795fe4388bb67548bb4960c1f/wal-000000013 (ops 61-65)
I20260812 06:18:24.401834   931 log.cc:1079] T a31ccba795fe4388bb67548bb4960c1f P 751ad1762ccf4a819ab73286727685e9: Deleting log segment in path: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502530812-810-0/minicluster-data/ts-0-root/wals/a31ccba795fe4388bb67548bb4960c1f/wal-000000014 (ops 66-70)
I20260812 06:18:24.430929   931 maintenance_manager.cc:643] P 751ad1762ccf4a819ab73286727685e9: LogGCOp(a31ccba795fe4388bb67548bb4960c1f) complete. Timing: real 0.030s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:18:24.431474  1006 maintenance_manager.cc:419] P 751ad1762ccf4a819ab73286727685e9: Scheduling UndoDeltaBlockGCOp(a31ccba795fe4388bb67548bb4960c1f): 472 bytes on disk
I20260812 06:18:24.431972   931 maintenance_manager.cc:643] P 751ad1762ccf4a819ab73286727685e9: UndoDeltaBlockGCOp(a31ccba795fe4388bb67548bb4960c1f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":67,"lbm_reads_lt_1ms":4}
I20260812 06:18:24.432459  1006 maintenance_manager.cc:419] P 751ad1762ccf4a819ab73286727685e9: Scheduling FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f): perf score=3.181125
I20260812 06:18:24.449811   931 maintenance_manager.cc:643] P 751ad1762ccf4a819ab73286727685e9: FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f) complete. Timing: real 0.017s	user 0.010s	sys 0.005s Metrics: {"bytes_written":4512902,"delete_count":0,"lbm_write_time_us":7294,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:24.450238  1006 maintenance_manager.cc:419] P 751ad1762ccf4a819ab73286727685e9: Scheduling FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f): perf score=2.188937
I20260812 06:18:24.459640   931 maintenance_manager.cc:643] P 751ad1762ccf4a819ab73286727685e9: FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3493,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:24.460232  1006 maintenance_manager.cc:419] P 751ad1762ccf4a819ab73286727685e9: Scheduling MajorDeltaCompactionOp(a31ccba795fe4388bb67548bb4960c1f): perf score=1.000000
I20260812 06:18:24.647595   931 maintenance_manager.cc:643] P 751ad1762ccf4a819ab73286727685e9: MajorDeltaCompactionOp(a31ccba795fe4388bb67548bb4960c1f) complete. Timing: real 0.187s	user 0.144s	sys 0.043s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979739,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":194,"lbm_read_time_us":13640,"lbm_reads_lt_1ms":774,"lbm_write_time_us":37722,"lbm_writes_lt_1ms":743,"mutex_wait_us":57,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":18816,"thread_start_us":83,"threads_started":1,"update_count":3500}
I20260812 06:18:24.648231  1006 maintenance_manager.cc:419] P 751ad1762ccf4a819ab73286727685e9: Scheduling FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f): perf score=14.095187
I20260812 06:18:24.703786   931 maintenance_manager.cc:643] P 751ad1762ccf4a819ab73286727685e9: FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f) complete. Timing: real 0.055s	user 0.029s	sys 0.025s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":23044,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:24.704476  1006 maintenance_manager.cc:419] P 751ad1762ccf4a819ab73286727685e9: Scheduling FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f): perf score=2.188937
I20260812 06:18:24.727559   931 maintenance_manager.cc:643] P 751ad1762ccf4a819ab73286727685e9: FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f) complete. Timing: real 0.023s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4266756,"delete_count":0,"lbm_write_time_us":5589,"lbm_writes_lt_1ms":107,"reinsert_count":0,"update_count":520}
I20260812 06:18:24.727998  1006 maintenance_manager.cc:419] P 751ad1762ccf4a819ab73286727685e9: Scheduling FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f): perf score=2.188937
I20260812 06:18:24.737900   931 maintenance_manager.cc:643] P 751ad1762ccf4a819ab73286727685e9: FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3938559,"delete_count":0,"lbm_write_time_us":3625,"lbm_writes_lt_1ms":99,"reinsert_count":0,"update_count":480}
I20260812 06:18:24.738370  1006 maintenance_manager.cc:419] P 751ad1762ccf4a819ab73286727685e9: Scheduling MajorDeltaCompactionOp(a31ccba795fe4388bb67548bb4960c1f): perf score=1.000000
I20260812 06:18:24.905006   931 maintenance_manager.cc:643] P 751ad1762ccf4a819ab73286727685e9: MajorDeltaCompactionOp(a31ccba795fe4388bb67548bb4960c1f) complete. Timing: real 0.166s	user 0.137s	sys 0.029s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877218,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":930,"lbm_read_time_us":12790,"lbm_reads_lt_1ms":673,"lbm_write_time_us":35366,"lbm_writes_lt_1ms":643,"mutex_wait_us":323,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":15744,"update_count":3000}
I20260812 06:18:24.905778  1006 maintenance_manager.cc:419] P 751ad1762ccf4a819ab73286727685e9: Scheduling FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f): perf score=14.095187
I20260812 06:18:24.956521   931 maintenance_manager.cc:643] P 751ad1762ccf4a819ab73286727685e9: FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f) complete. Timing: real 0.051s	user 0.021s	sys 0.027s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20523,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:24.957012  1006 maintenance_manager.cc:419] P 751ad1762ccf4a819ab73286727685e9: Scheduling FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f): perf score=2.188937
I20260812 06:18:24.975982   931 maintenance_manager.cc:643] P 751ad1762ccf4a819ab73286727685e9: FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f) complete. Timing: real 0.019s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4451,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:24.976452  1006 maintenance_manager.cc:419] P 751ad1762ccf4a819ab73286727685e9: Scheduling FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f): perf score=2.188937
I20260812 06:18:24.986577   931 maintenance_manager.cc:643] P 751ad1762ccf4a819ab73286727685e9: FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f) complete. Timing: real 0.010s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3963,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:24.987015  1006 maintenance_manager.cc:419] P 751ad1762ccf4a819ab73286727685e9: Scheduling MajorDeltaCompactionOp(a31ccba795fe4388bb67548bb4960c1f): perf score=1.000000
I20260812 06:18:25.153247   931 maintenance_manager.cc:643] P 751ad1762ccf4a819ab73286727685e9: MajorDeltaCompactionOp(a31ccba795fe4388bb67548bb4960c1f) complete. Timing: real 0.166s	user 0.138s	sys 0.028s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877219,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":570,"lbm_read_time_us":11904,"lbm_reads_lt_1ms":673,"lbm_write_time_us":34897,"lbm_writes_lt_1ms":643,"mutex_wait_us":282,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":9856,"update_count":3000}
I20260812 06:18:25.153894  1006 maintenance_manager.cc:419] P 751ad1762ccf4a819ab73286727685e9: Scheduling FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f): perf score=14.095187
I20260812 06:18:25.200343   931 maintenance_manager.cc:643] P 751ad1762ccf4a819ab73286727685e9: FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f) complete. Timing: real 0.046s	user 0.020s	sys 0.023s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19657,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:25.201025  1006 maintenance_manager.cc:419] P 751ad1762ccf4a819ab73286727685e9: Scheduling FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f): perf score=2.188937
I20260812 06:18:25.214761   931 maintenance_manager.cc:643] P 751ad1762ccf4a819ab73286727685e9: FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f) complete. Timing: real 0.014s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4769,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:25.215267  1006 maintenance_manager.cc:419] P 751ad1762ccf4a819ab73286727685e9: Scheduling MajorDeltaCompactionOp(a31ccba795fe4388bb67548bb4960c1f): perf score=1.000000
I20260812 06:18:25.373158   931 maintenance_manager.cc:643] P 751ad1762ccf4a819ab73286727685e9: MajorDeltaCompactionOp(a31ccba795fe4388bb67548bb4960c1f) complete. Timing: real 0.157s	user 0.117s	sys 0.028s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":341,"lbm_read_time_us":8708,"lbm_reads_lt_1ms":564,"lbm_write_time_us":27293,"lbm_writes_lt_1ms":543,"mutex_wait_us":44,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10880,"update_count":2500}
I20260812 06:18:25.373968  1006 maintenance_manager.cc:419] P 751ad1762ccf4a819ab73286727685e9: Scheduling FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f): perf score=14.095187
I20260812 06:18:25.423539   931 maintenance_manager.cc:643] P 751ad1762ccf4a819ab73286727685e9: FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f) complete. Timing: real 0.049s	user 0.026s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21256,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:25.424088  1006 maintenance_manager.cc:419] P 751ad1762ccf4a819ab73286727685e9: Scheduling MajorDeltaCompactionOp(a31ccba795fe4388bb67548bb4960c1f): perf score=1.000000
I20260812 06:18:25.587673   931 maintenance_manager.cc:643] P 751ad1762ccf4a819ab73286727685e9: MajorDeltaCompactionOp(a31ccba795fe4388bb67548bb4960c1f) complete. Timing: real 0.163s	user 0.113s	sys 0.045s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672158,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":785,"lbm_read_time_us":10722,"lbm_reads_lt_1ms":463,"lbm_write_time_us":26811,"lbm_writes_lt_1ms":443,"mutex_wait_us":280,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8704,"update_count":2000}
I20260812 06:18:25.588435  1006 maintenance_manager.cc:419] P 751ad1762ccf4a819ab73286727685e9: Scheduling FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f): perf score=10.126437
I20260812 06:18:25.630692   931 maintenance_manager.cc:643] P 751ad1762ccf4a819ab73286727685e9: FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f) complete. Timing: real 0.042s	user 0.026s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17875,"lbm_writes_lt_1ms":303,"reinsert_count":0,"spinlock_wait_cycles":19712,"update_count":1500}
I20260812 06:18:25.631335  1006 maintenance_manager.cc:419] P 751ad1762ccf4a819ab73286727685e9: Scheduling FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f): perf score=2.188937
I20260812 06:18:25.646871   931 maintenance_manager.cc:643] P 751ad1762ccf4a819ab73286727685e9: FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f) complete. Timing: real 0.015s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5865,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:25.647356  1006 maintenance_manager.cc:419] P 751ad1762ccf4a819ab73286727685e9: Scheduling MajorDeltaCompactionOp(a31ccba795fe4388bb67548bb4960c1f): perf score=1.000000
I20260812 06:18:25.804487   931 maintenance_manager.cc:643] P 751ad1762ccf4a819ab73286727685e9: MajorDeltaCompactionOp(a31ccba795fe4388bb67548bb4960c1f) complete. Timing: real 0.157s	user 0.123s	sys 0.028s 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":934,"lbm_read_time_us":10262,"lbm_reads_lt_1ms":472,"lbm_write_time_us":29233,"lbm_writes_lt_1ms":443,"mutex_wait_us":273,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2000}
I20260812 06:18:25.805023  1006 maintenance_manager.cc:419] P 751ad1762ccf4a819ab73286727685e9: Scheduling FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f): perf score=10.126437
I20260812 06:18:25.857476   931 maintenance_manager.cc:643] P 751ad1762ccf4a819ab73286727685e9: FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f) complete. Timing: real 0.052s	user 0.023s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18549,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:25.857949  1006 maintenance_manager.cc:419] P 751ad1762ccf4a819ab73286727685e9: Scheduling FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f): perf score=2.188937
I20260812 06:18:25.868135   931 maintenance_manager.cc:643] P 751ad1762ccf4a819ab73286727685e9: FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4096,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:25.868614  1006 maintenance_manager.cc:419] P 751ad1762ccf4a819ab73286727685e9: Scheduling FlushMRSOp(a31ccba795fe4388bb67548bb4960c1f): perf score=1.000000
I20260812 06:18:25.911206   931 maintenance_manager.cc:643] P 751ad1762ccf4a819ab73286727685e9: FlushMRSOp(a31ccba795fe4388bb67548bb4960c1f) complete. Timing: real 0.042s	user 0.030s	sys 0.005s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":58,"dirs.run_cpu_time_us":227,"dirs.run_wall_time_us":1391,"drs_written":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2041,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:18:25.911942  1006 maintenance_manager.cc:419] P 751ad1762ccf4a819ab73286727685e9: Scheduling LogGCOp(a31ccba795fe4388bb67548bb4960c1f): free 121459505 bytes of WAL
I20260812 06:18:25.912176   931 log_reader.cc:385] T a31ccba795fe4388bb67548bb4960c1f: removed 12 log segments from log reader
I20260812 06:18:25.912221   931 log.cc:1079] T a31ccba795fe4388bb67548bb4960c1f P 751ad1762ccf4a819ab73286727685e9: Deleting log segment in path: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502530812-810-0/minicluster-data/ts-0-root/wals/a31ccba795fe4388bb67548bb4960c1f/wal-000000015 (ops 71-75)
I20260812 06:18:25.912249   931 log.cc:1079] T a31ccba795fe4388bb67548bb4960c1f P 751ad1762ccf4a819ab73286727685e9: Deleting log segment in path: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502530812-810-0/minicluster-data/ts-0-root/wals/a31ccba795fe4388bb67548bb4960c1f/wal-000000016 (ops 76-80)
I20260812 06:18:25.912308   931 log.cc:1079] T a31ccba795fe4388bb67548bb4960c1f P 751ad1762ccf4a819ab73286727685e9: Deleting log segment in path: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502530812-810-0/minicluster-data/ts-0-root/wals/a31ccba795fe4388bb67548bb4960c1f/wal-000000017 (ops 81-85)
I20260812 06:18:25.912352   931 log.cc:1079] T a31ccba795fe4388bb67548bb4960c1f P 751ad1762ccf4a819ab73286727685e9: Deleting log segment in path: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502530812-810-0/minicluster-data/ts-0-root/wals/a31ccba795fe4388bb67548bb4960c1f/wal-000000018 (ops 86-90)
I20260812 06:18:25.912393   931 log.cc:1079] T a31ccba795fe4388bb67548bb4960c1f P 751ad1762ccf4a819ab73286727685e9: Deleting log segment in path: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502530812-810-0/minicluster-data/ts-0-root/wals/a31ccba795fe4388bb67548bb4960c1f/wal-000000019 (ops 91-95)
I20260812 06:18:25.912437   931 log.cc:1079] T a31ccba795fe4388bb67548bb4960c1f P 751ad1762ccf4a819ab73286727685e9: Deleting log segment in path: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502530812-810-0/minicluster-data/ts-0-root/wals/a31ccba795fe4388bb67548bb4960c1f/wal-000000020 (ops 96-100)
I20260812 06:18:25.912477   931 log.cc:1079] T a31ccba795fe4388bb67548bb4960c1f P 751ad1762ccf4a819ab73286727685e9: Deleting log segment in path: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502530812-810-0/minicluster-data/ts-0-root/wals/a31ccba795fe4388bb67548bb4960c1f/wal-000000021 (ops 101-105)
I20260812 06:18:25.912528   931 log.cc:1079] T a31ccba795fe4388bb67548bb4960c1f P 751ad1762ccf4a819ab73286727685e9: Deleting log segment in path: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502530812-810-0/minicluster-data/ts-0-root/wals/a31ccba795fe4388bb67548bb4960c1f/wal-000000022 (ops 106-110)
I20260812 06:18:25.912570   931 log.cc:1079] T a31ccba795fe4388bb67548bb4960c1f P 751ad1762ccf4a819ab73286727685e9: Deleting log segment in path: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502530812-810-0/minicluster-data/ts-0-root/wals/a31ccba795fe4388bb67548bb4960c1f/wal-000000023 (ops 111-115)
I20260812 06:18:25.912596   931 log.cc:1079] T a31ccba795fe4388bb67548bb4960c1f P 751ad1762ccf4a819ab73286727685e9: Deleting log segment in path: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502530812-810-0/minicluster-data/ts-0-root/wals/a31ccba795fe4388bb67548bb4960c1f/wal-000000024 (ops 116-120)
I20260812 06:18:25.912635   931 log.cc:1079] T a31ccba795fe4388bb67548bb4960c1f P 751ad1762ccf4a819ab73286727685e9: Deleting log segment in path: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502530812-810-0/minicluster-data/ts-0-root/wals/a31ccba795fe4388bb67548bb4960c1f/wal-000000025 (ops 121-125)
I20260812 06:18:25.912675   931 log.cc:1079] T a31ccba795fe4388bb67548bb4960c1f P 751ad1762ccf4a819ab73286727685e9: Deleting log segment in path: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502530812-810-0/minicluster-data/ts-0-root/wals/a31ccba795fe4388bb67548bb4960c1f/wal-000000026 (ops 126-130)
I20260812 06:18:25.939481   931 maintenance_manager.cc:643] P 751ad1762ccf4a819ab73286727685e9: LogGCOp(a31ccba795fe4388bb67548bb4960c1f) complete. Timing: real 0.027s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:18:25.939882  1006 maintenance_manager.cc:419] P 751ad1762ccf4a819ab73286727685e9: Scheduling UndoDeltaBlockGCOp(a31ccba795fe4388bb67548bb4960c1f): 482 bytes on disk
I20260812 06:18:25.940286   931 maintenance_manager.cc:643] P 751ad1762ccf4a819ab73286727685e9: UndoDeltaBlockGCOp(a31ccba795fe4388bb67548bb4960c1f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4}
I20260812 06:18:25.940758  1006 maintenance_manager.cc:419] P 751ad1762ccf4a819ab73286727685e9: Scheduling FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f): perf score=3.181125
I20260812 06:18:25.954115   931 maintenance_manager.cc:643] P 751ad1762ccf4a819ab73286727685e9: FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f) complete. Timing: real 0.013s	user 0.003s	sys 0.006s Metrics: {"bytes_written":4389831,"delete_count":0,"lbm_write_time_us":4242,"lbm_writes_lt_1ms":110,"reinsert_count":0,"update_count":535}
I20260812 06:18:25.954771  1006 maintenance_manager.cc:419] P 751ad1762ccf4a819ab73286727685e9: Scheduling FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f): perf score=2.188937
I20260812 06:18:25.964298   931 maintenance_manager.cc:643] P 751ad1762ccf4a819ab73286727685e9: FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3815484,"delete_count":0,"lbm_write_time_us":3651,"lbm_writes_lt_1ms":96,"reinsert_count":0,"update_count":465}
I20260812 06:18:25.964793  1006 maintenance_manager.cc:419] P 751ad1762ccf4a819ab73286727685e9: Scheduling MajorDeltaCompactionOp(a31ccba795fe4388bb67548bb4960c1f): perf score=1.000000
I20260812 06:18:26.153228   931 maintenance_manager.cc:643] P 751ad1762ccf4a819ab73286727685e9: MajorDeltaCompactionOp(a31ccba795fe4388bb67548bb4960c1f) complete. Timing: real 0.188s	user 0.141s	sys 0.042s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877336,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":654,"lbm_read_time_us":13317,"lbm_reads_lt_1ms":674,"lbm_write_time_us":38048,"lbm_writes_lt_1ms":643,"mutex_wait_us":346,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1280,"thread_start_us":75,"threads_started":1,"update_count":3000}
I20260812 06:18:26.153949  1006 maintenance_manager.cc:419] P 751ad1762ccf4a819ab73286727685e9: Scheduling FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f): perf score=14.095187
I20260812 06:18:26.209265   931 maintenance_manager.cc:643] P 751ad1762ccf4a819ab73286727685e9: FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f) complete. Timing: real 0.055s	user 0.018s	sys 0.024s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20500,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:26.209761  1006 maintenance_manager.cc:419] P 751ad1762ccf4a819ab73286727685e9: Scheduling FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f): perf score=2.188937
I20260812 06:18:26.225365   931 maintenance_manager.cc:643] P 751ad1762ccf4a819ab73286727685e9: FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f) complete. Timing: real 0.015s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5469,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:26.225896  1006 maintenance_manager.cc:419] P 751ad1762ccf4a819ab73286727685e9: Scheduling MajorDeltaCompactionOp(a31ccba795fe4388bb67548bb4960c1f): perf score=1.000000
I20260812 06:18:26.370602   931 maintenance_manager.cc:643] P 751ad1762ccf4a819ab73286727685e9: MajorDeltaCompactionOp(a31ccba795fe4388bb67548bb4960c1f) complete. Timing: real 0.144s	user 0.118s	sys 0.025s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":279,"lbm_read_time_us":9381,"lbm_reads_lt_1ms":564,"lbm_write_time_us":28812,"lbm_writes_lt_1ms":543,"mutex_wait_us":31,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8704,"update_count":2500}
I20260812 06:18:26.371845  1006 maintenance_manager.cc:419] P 751ad1762ccf4a819ab73286727685e9: Scheduling FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f): perf score=11.118625
I20260812 06:18:26.407584   931 maintenance_manager.cc:643] P 751ad1762ccf4a819ab73286727685e9: FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f) complete. Timing: real 0.036s	user 0.006s	sys 0.028s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":15705,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:26.408267  1006 maintenance_manager.cc:419] P 751ad1762ccf4a819ab73286727685e9: Scheduling FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f): perf score=2.188937
I20260812 06:18:26.423316   931 maintenance_manager.cc:643] P 751ad1762ccf4a819ab73286727685e9: FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f) complete. Timing: real 0.015s	user 0.012s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5793,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:26.423872  1006 maintenance_manager.cc:419] P 751ad1762ccf4a819ab73286727685e9: Scheduling MajorDeltaCompactionOp(a31ccba795fe4388bb67548bb4960c1f): perf score=1.000000
I20260812 06:18:26.543594   931 maintenance_manager.cc:643] P 751ad1762ccf4a819ab73286727685e9: MajorDeltaCompactionOp(a31ccba795fe4388bb67548bb4960c1f) complete. Timing: real 0.119s	user 0.089s	sys 0.030s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672267,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":205,"lbm_read_time_us":7713,"lbm_reads_lt_1ms":468,"lbm_write_time_us":23839,"lbm_writes_lt_1ms":443,"mutex_wait_us":2,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:26.544193  1006 maintenance_manager.cc:419] P 751ad1762ccf4a819ab73286727685e9: Scheduling FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f): perf score=10.126437
I20260812 06:18:26.587345   931 maintenance_manager.cc:643] P 751ad1762ccf4a819ab73286727685e9: FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f) complete. Timing: real 0.043s	user 0.018s	sys 0.015s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15570,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:26.587857  1006 maintenance_manager.cc:419] P 751ad1762ccf4a819ab73286727685e9: Scheduling FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f): perf score=2.188937
I20260812 06:18:26.598351   931 maintenance_manager.cc:643] P 751ad1762ccf4a819ab73286727685e9: FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4076,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:26.598922  1006 maintenance_manager.cc:419] P 751ad1762ccf4a819ab73286727685e9: Scheduling MajorDeltaCompactionOp(a31ccba795fe4388bb67548bb4960c1f): perf score=1.000000
I20260812 06:18:26.723853   931 maintenance_manager.cc:643] P 751ad1762ccf4a819ab73286727685e9: MajorDeltaCompactionOp(a31ccba795fe4388bb67548bb4960c1f) complete. Timing: real 0.125s	user 0.100s	sys 0.024s 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":731,"lbm_read_time_us":8955,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25429,"lbm_writes_lt_1ms":443,"mutex_wait_us":310,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2000}
I20260812 06:18:26.726761  1006 maintenance_manager.cc:419] P 751ad1762ccf4a819ab73286727685e9: Scheduling FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f): perf score=10.126437
I20260812 06:18:26.776809   931 maintenance_manager.cc:643] P 751ad1762ccf4a819ab73286727685e9: FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f) complete. Timing: real 0.050s	user 0.013s	sys 0.029s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":16099,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:26.777392  1006 maintenance_manager.cc:419] P 751ad1762ccf4a819ab73286727685e9: Scheduling FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f): perf score=2.188937
I20260812 06:18:26.788537   931 maintenance_manager.cc:643] P 751ad1762ccf4a819ab73286727685e9: FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4323,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:26.788982  1006 maintenance_manager.cc:419] P 751ad1762ccf4a819ab73286727685e9: Scheduling MajorDeltaCompactionOp(a31ccba795fe4388bb67548bb4960c1f): perf score=1.000000
I20260812 06:18:26.936033   931 maintenance_manager.cc:643] P 751ad1762ccf4a819ab73286727685e9: MajorDeltaCompactionOp(a31ccba795fe4388bb67548bb4960c1f) complete. Timing: real 0.147s	user 0.106s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":166,"lbm_read_time_us":10048,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24240,"lbm_writes_lt_1ms":443,"mutex_wait_us":25,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":65024,"update_count":2000}
I20260812 06:18:26.936761  1006 maintenance_manager.cc:419] P 751ad1762ccf4a819ab73286727685e9: Scheduling FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f): perf score=10.126437
I20260812 06:18:26.986119   931 maintenance_manager.cc:643] P 751ad1762ccf4a819ab73286727685e9: FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f) complete. Timing: real 0.049s	user 0.025s	sys 0.012s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":18226,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:26.986686  1006 maintenance_manager.cc:419] P 751ad1762ccf4a819ab73286727685e9: Scheduling FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f): perf score=2.188937
I20260812 06:18:26.996991   931 maintenance_manager.cc:643] P 751ad1762ccf4a819ab73286727685e9: FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4022,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:26.997601  1006 maintenance_manager.cc:419] P 751ad1762ccf4a819ab73286727685e9: Scheduling MajorDeltaCompactionOp(a31ccba795fe4388bb67548bb4960c1f): perf score=1.000000
I20260812 06:18:27.129210   931 maintenance_manager.cc:643] P 751ad1762ccf4a819ab73286727685e9: MajorDeltaCompactionOp(a31ccba795fe4388bb67548bb4960c1f) complete. Timing: real 0.131s	user 0.095s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1065,"lbm_read_time_us":9023,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25557,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:27.129798  1006 maintenance_manager.cc:419] P 751ad1762ccf4a819ab73286727685e9: Scheduling FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f): perf score=10.126437
I20260812 06:18:27.170601   931 maintenance_manager.cc:643] P 751ad1762ccf4a819ab73286727685e9: FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f) complete. Timing: real 0.041s	user 0.033s	sys 0.007s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":17510,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:27.171156  1006 maintenance_manager.cc:419] P 751ad1762ccf4a819ab73286727685e9: Scheduling FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f): perf score=2.188937
I20260812 06:18:27.181671   931 maintenance_manager.cc:643] P 751ad1762ccf4a819ab73286727685e9: FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4067,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:27.182514  1006 maintenance_manager.cc:419] P 751ad1762ccf4a819ab73286727685e9: Scheduling MajorDeltaCompactionOp(a31ccba795fe4388bb67548bb4960c1f): perf score=1.000000
I20260812 06:18:27.302047   931 maintenance_manager.cc:643] P 751ad1762ccf4a819ab73286727685e9: MajorDeltaCompactionOp(a31ccba795fe4388bb67548bb4960c1f) complete. Timing: real 0.119s	user 0.090s	sys 0.029s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":925,"lbm_read_time_us":8078,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21947,"lbm_writes_lt_1ms":443,"mutex_wait_us":81,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:27.302754  1006 maintenance_manager.cc:419] P 751ad1762ccf4a819ab73286727685e9: Scheduling FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f): perf score=10.126437
I20260812 06:18:27.344988   931 maintenance_manager.cc:643] P 751ad1762ccf4a819ab73286727685e9: FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f) complete. Timing: real 0.042s	user 0.012s	sys 0.027s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17187,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:27.345424  1006 maintenance_manager.cc:419] P 751ad1762ccf4a819ab73286727685e9: Scheduling FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f): perf score=2.188937
I20260812 06:18:27.357278   931 maintenance_manager.cc:643] P 751ad1762ccf4a819ab73286727685e9: FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3968,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:27.357847  1006 maintenance_manager.cc:419] P 751ad1762ccf4a819ab73286727685e9: Scheduling FlushMRSOp(a31ccba795fe4388bb67548bb4960c1f): perf score=1.000000
I20260812 06:18:27.385582   931 maintenance_manager.cc:643] P 751ad1762ccf4a819ab73286727685e9: FlushMRSOp(a31ccba795fe4388bb67548bb4960c1f) complete. Timing: real 0.028s	user 0.026s	sys 0.000s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":62,"dirs.run_cpu_time_us":222,"dirs.run_wall_time_us":1369,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1563,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:18:27.386366  1006 maintenance_manager.cc:419] P 751ad1762ccf4a819ab73286727685e9: Scheduling LogGCOp(a31ccba795fe4388bb67548bb4960c1f): free 136728518 bytes of WAL
I20260812 06:18:27.386653   931 log_reader.cc:385] T a31ccba795fe4388bb67548bb4960c1f: removed 13 log segments from log reader
I20260812 06:18:27.386719   931 log.cc:1079] T a31ccba795fe4388bb67548bb4960c1f P 751ad1762ccf4a819ab73286727685e9: Deleting log segment in path: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502530812-810-0/minicluster-data/ts-0-root/wals/a31ccba795fe4388bb67548bb4960c1f/wal-000000027 (ops 131-135)
I20260812 06:18:27.386773   931 log.cc:1079] T a31ccba795fe4388bb67548bb4960c1f P 751ad1762ccf4a819ab73286727685e9: Deleting log segment in path: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502530812-810-0/minicluster-data/ts-0-root/wals/a31ccba795fe4388bb67548bb4960c1f/wal-000000028 (ops 136-140)
I20260812 06:18:27.386831   931 log.cc:1079] T a31ccba795fe4388bb67548bb4960c1f P 751ad1762ccf4a819ab73286727685e9: Deleting log segment in path: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502530812-810-0/minicluster-data/ts-0-root/wals/a31ccba795fe4388bb67548bb4960c1f/wal-000000029 (ops 141-145)
I20260812 06:18:27.386873   931 log.cc:1079] T a31ccba795fe4388bb67548bb4960c1f P 751ad1762ccf4a819ab73286727685e9: Deleting log segment in path: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502530812-810-0/minicluster-data/ts-0-root/wals/a31ccba795fe4388bb67548bb4960c1f/wal-000000030 (ops 146-150)
I20260812 06:18:27.386907   931 log.cc:1079] T a31ccba795fe4388bb67548bb4960c1f P 751ad1762ccf4a819ab73286727685e9: Deleting log segment in path: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502530812-810-0/minicluster-data/ts-0-root/wals/a31ccba795fe4388bb67548bb4960c1f/wal-000000031 (ops 151-155)
I20260812 06:18:27.386945   931 log.cc:1079] T a31ccba795fe4388bb67548bb4960c1f P 751ad1762ccf4a819ab73286727685e9: Deleting log segment in path: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502530812-810-0/minicluster-data/ts-0-root/wals/a31ccba795fe4388bb67548bb4960c1f/wal-000000032 (ops 156-160)
I20260812 06:18:27.386981   931 log.cc:1079] T a31ccba795fe4388bb67548bb4960c1f P 751ad1762ccf4a819ab73286727685e9: Deleting log segment in path: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502530812-810-0/minicluster-data/ts-0-root/wals/a31ccba795fe4388bb67548bb4960c1f/wal-000000033 (ops 161-165)
I20260812 06:18:27.387020   931 log.cc:1079] T a31ccba795fe4388bb67548bb4960c1f P 751ad1762ccf4a819ab73286727685e9: Deleting log segment in path: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502530812-810-0/minicluster-data/ts-0-root/wals/a31ccba795fe4388bb67548bb4960c1f/wal-000000034 (ops 166-170)
I20260812 06:18:27.387061   931 log.cc:1079] T a31ccba795fe4388bb67548bb4960c1f P 751ad1762ccf4a819ab73286727685e9: Deleting log segment in path: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502530812-810-0/minicluster-data/ts-0-root/wals/a31ccba795fe4388bb67548bb4960c1f/wal-000000035 (ops 171-175)
I20260812 06:18:27.387099   931 log.cc:1079] T a31ccba795fe4388bb67548bb4960c1f P 751ad1762ccf4a819ab73286727685e9: Deleting log segment in path: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502530812-810-0/minicluster-data/ts-0-root/wals/a31ccba795fe4388bb67548bb4960c1f/wal-000000036 (ops 176-180)
I20260812 06:18:27.387135   931 log.cc:1079] T a31ccba795fe4388bb67548bb4960c1f P 751ad1762ccf4a819ab73286727685e9: Deleting log segment in path: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502530812-810-0/minicluster-data/ts-0-root/wals/a31ccba795fe4388bb67548bb4960c1f/wal-000000037 (ops 181-185)
I20260812 06:18:27.387171   931 log.cc:1079] T a31ccba795fe4388bb67548bb4960c1f P 751ad1762ccf4a819ab73286727685e9: Deleting log segment in path: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502530812-810-0/minicluster-data/ts-0-root/wals/a31ccba795fe4388bb67548bb4960c1f/wal-000000038 (ops 186-190)
I20260812 06:18:27.387208   931 log.cc:1079] T a31ccba795fe4388bb67548bb4960c1f P 751ad1762ccf4a819ab73286727685e9: Deleting log segment in path: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515502530812-810-0/minicluster-data/ts-0-root/wals/a31ccba795fe4388bb67548bb4960c1f/wal-000000039 (ops 191-195)
I20260812 06:18:27.419543   931 maintenance_manager.cc:643] P 751ad1762ccf4a819ab73286727685e9: LogGCOp(a31ccba795fe4388bb67548bb4960c1f) complete. Timing: real 0.033s	user 0.000s	sys 0.032s Metrics: {}
I20260812 06:18:27.420127  1006 maintenance_manager.cc:419] P 751ad1762ccf4a819ab73286727685e9: Scheduling UndoDeltaBlockGCOp(a31ccba795fe4388bb67548bb4960c1f): 483 bytes on disk
I20260812 06:18:27.420683   931 maintenance_manager.cc:643] P 751ad1762ccf4a819ab73286727685e9: UndoDeltaBlockGCOp(a31ccba795fe4388bb67548bb4960c1f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":76,"lbm_reads_lt_1ms":4}
I20260812 06:18:27.421484  1006 maintenance_manager.cc:419] P 751ad1762ccf4a819ab73286727685e9: Scheduling FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f): perf score=5.165500
I20260812 06:18:27.441236   931 maintenance_manager.cc:643] P 751ad1762ccf4a819ab73286727685e9: FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f) complete. Timing: real 0.020s	user 0.010s	sys 0.007s Metrics: {"bytes_written":6400018,"delete_count":0,"lbm_write_time_us":8191,"lbm_writes_lt_1ms":159,"reinsert_count":0,"update_count":780}
I20260812 06:18:27.441705  1006 maintenance_manager.cc:419] P 751ad1762ccf4a819ab73286727685e9: Scheduling FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f): perf score=1.000000
I20260812 06:18:27.451256   931 maintenance_manager.cc:643] P 751ad1762ccf4a819ab73286727685e9: FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f) complete. Timing: real 0.009s	user 0.001s	sys 0.008s Metrics: {"bytes_written":1805252,"delete_count":0,"lbm_write_time_us":3203,"lbm_writes_lt_1ms":47,"reinsert_count":0,"update_count":220}
I20260812 06:18:27.451701  1006 maintenance_manager.cc:419] P 751ad1762ccf4a819ab73286727685e9: Scheduling MajorDeltaCompactionOp(a31ccba795fe4388bb67548bb4960c1f): perf score=1.000000
I20260812 06:18:27.528893   810 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.693s	user 1.774s	sys 0.094s
I20260812 06:18:27.613950   931 maintenance_manager.cc:643] P 751ad1762ccf4a819ab73286727685e9: MajorDeltaCompactionOp(a31ccba795fe4388bb67548bb4960c1f) complete. Timing: real 0.162s	user 0.122s	sys 0.040s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877286,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":657,"lbm_read_time_us":12755,"lbm_reads_lt_1ms":666,"lbm_write_time_us":32242,"lbm_writes_lt_1ms":643,"mutex_wait_us":344,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":14720,"thread_start_us":74,"threads_started":1,"update_count":3000}
I20260812 06:18:27.614708  1006 maintenance_manager.cc:419] P 751ad1762ccf4a819ab73286727685e9: Scheduling FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f): perf score=6.157687
I20260812 06:18:27.619801   810 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.090s	user 0.002s	sys 0.004s
I20260812 06:18:27.620435   810 tablet_server.cc:179] TabletServer@127.0.202.129:0 shutting down...
I20260812 06:18:27.638309   931 maintenance_manager.cc:643] P 751ad1762ccf4a819ab73286727685e9: FlushDeltaMemStoresOp(a31ccba795fe4388bb67548bb4960c1f) complete. Timing: real 0.022s	user 0.015s	sys 0.004s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":9505,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:18:27.638959   810 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:27.639344   810 tablet_replica.cc:333] T a31ccba795fe4388bb67548bb4960c1f P 751ad1762ccf4a819ab73286727685e9: stopping tablet replica
I20260812 06:18:27.639578   810 raft_consensus.cc:2243] T a31ccba795fe4388bb67548bb4960c1f P 751ad1762ccf4a819ab73286727685e9 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:27.639818   810 raft_consensus.cc:2272] T a31ccba795fe4388bb67548bb4960c1f P 751ad1762ccf4a819ab73286727685e9 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:27.656492   810 tablet_server.cc:196] TabletServer@127.0.202.129:0 shutdown complete.
I20260812 06:18:27.665853   810 master.cc:562] Master@127.0.202.190:35327 shutting down...
I20260812 06:18:27.669404   810 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 6448a8f25c12406d9035a6d5a5f61ed4 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:27.669600   810 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 6448a8f25c12406d9035a6d5a5f61ed4 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:27.669685   810 tablet_replica.cc:333] T 00000000000000000000000000000000 P 6448a8f25c12406d9035a6d5a5f61ed4: stopping tablet replica
I20260812 06:18:27.681910   810 master.cc:584] Master@127.0.202.190:35327 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5226 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:18:27.767707   810 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.0.202.190:39303
I20260812 06:18:27.768121   810 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:27.770159  1042 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:27.770202  1043 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:27.770296  1045 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:27.770386   810 server_base.cc:1061] running on GCE node
I20260812 06:18:27.770619   810 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:27.770661   810 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:27.770677   810 hybrid_clock.cc:648] HybridClock initialized: now 1786515507770677 us; error 0 us; skew 500 ppm
I20260812 06:18:27.771523   810 webserver.cc:533] Webserver started at http://127.0.202.190:43743/ using document root <none> and password file <none>
I20260812 06:18:27.771696   810 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:27.771759   810 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:27.771839   810 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:27.772241   810 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502530812-810-0/minicluster-data/master-0-root/instance:
uuid: "1b1a88a7eaf246f0a1201c5f04bacef0"
format_stamp: "Formatted at 2026-08-12 06:18:27 on dist-test-slave-gp6n"
I20260812 06:18:27.773990   810 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:18:27.774950  1051 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:27.775194   810 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.000s
I20260812 06:18:27.775295   810 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502530812-810-0/minicluster-data/master-0-root
uuid: "1b1a88a7eaf246f0a1201c5f04bacef0"
format_stamp: "Formatted at 2026-08-12 06:18:27 on dist-test-slave-gp6n"
I20260812 06:18:27.775382   810 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502530812-810-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502530812-810-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502530812-810-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:27.802822   810 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:27.803243   810 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:27.807480   810 rpc_server.cc:307] RPC server started. Bound to: 127.0.202.190:39303
I20260812 06:18:27.809417  1114 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.0.202.190:39303 every 8 connection(s)
I20260812 06:18:27.815578  1115 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:27.825256  1115 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 1b1a88a7eaf246f0a1201c5f04bacef0: Bootstrap starting.
I20260812 06:18:27.826125  1115 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 1b1a88a7eaf246f0a1201c5f04bacef0: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:27.827211  1115 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 1b1a88a7eaf246f0a1201c5f04bacef0: No bootstrap required, opened a new log
I20260812 06:18:27.827656  1115 raft_consensus.cc:359] T 00000000000000000000000000000000 P 1b1a88a7eaf246f0a1201c5f04bacef0 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1b1a88a7eaf246f0a1201c5f04bacef0" member_type: VOTER }
I20260812 06:18:27.827744  1115 raft_consensus.cc:385] T 00000000000000000000000000000000 P 1b1a88a7eaf246f0a1201c5f04bacef0 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:27.827798  1115 raft_consensus.cc:740] T 00000000000000000000000000000000 P 1b1a88a7eaf246f0a1201c5f04bacef0 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 1b1a88a7eaf246f0a1201c5f04bacef0, State: Initialized, Role: FOLLOWER
I20260812 06:18:27.827980  1115 consensus_queue.cc:260] T 00000000000000000000000000000000 P 1b1a88a7eaf246f0a1201c5f04bacef0 [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: "1b1a88a7eaf246f0a1201c5f04bacef0" member_type: VOTER }
I20260812 06:18:27.828050  1115 raft_consensus.cc:399] T 00000000000000000000000000000000 P 1b1a88a7eaf246f0a1201c5f04bacef0 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:27.828109  1115 raft_consensus.cc:493] T 00000000000000000000000000000000 P 1b1a88a7eaf246f0a1201c5f04bacef0 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:27.828168  1115 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 1b1a88a7eaf246f0a1201c5f04bacef0 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:27.828859  1115 raft_consensus.cc:515] T 00000000000000000000000000000000 P 1b1a88a7eaf246f0a1201c5f04bacef0 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1b1a88a7eaf246f0a1201c5f04bacef0" member_type: VOTER }
I20260812 06:18:27.829011  1115 leader_election.cc:304] T 00000000000000000000000000000000 P 1b1a88a7eaf246f0a1201c5f04bacef0 [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: 1b1a88a7eaf246f0a1201c5f04bacef0; no voters: 
I20260812 06:18:27.829221  1115 leader_election.cc:290] T 00000000000000000000000000000000 P 1b1a88a7eaf246f0a1201c5f04bacef0 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:27.829372  1119 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 1b1a88a7eaf246f0a1201c5f04bacef0 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:27.829586  1119 raft_consensus.cc:697] T 00000000000000000000000000000000 P 1b1a88a7eaf246f0a1201c5f04bacef0 [term 1 LEADER]: Becoming Leader. State: Replica: 1b1a88a7eaf246f0a1201c5f04bacef0, State: Running, Role: LEADER
I20260812 06:18:27.829684  1115 sys_catalog.cc:565] T 00000000000000000000000000000000 P 1b1a88a7eaf246f0a1201c5f04bacef0 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:27.829742  1119 consensus_queue.cc:237] T 00000000000000000000000000000000 P 1b1a88a7eaf246f0a1201c5f04bacef0 [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: "1b1a88a7eaf246f0a1201c5f04bacef0" member_type: VOTER }
I20260812 06:18:27.830173  1120 sys_catalog.cc:455] T 00000000000000000000000000000000 P 1b1a88a7eaf246f0a1201c5f04bacef0 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "1b1a88a7eaf246f0a1201c5f04bacef0" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1b1a88a7eaf246f0a1201c5f04bacef0" member_type: VOTER } }
I20260812 06:18:27.830276  1120 sys_catalog.cc:458] T 00000000000000000000000000000000 P 1b1a88a7eaf246f0a1201c5f04bacef0 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:27.830382  1121 sys_catalog.cc:455] T 00000000000000000000000000000000 P 1b1a88a7eaf246f0a1201c5f04bacef0 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 1b1a88a7eaf246f0a1201c5f04bacef0. Latest consensus state: current_term: 1 leader_uuid: "1b1a88a7eaf246f0a1201c5f04bacef0" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1b1a88a7eaf246f0a1201c5f04bacef0" member_type: VOTER } }
I20260812 06:18:27.830478  1121 sys_catalog.cc:458] T 00000000000000000000000000000000 P 1b1a88a7eaf246f0a1201c5f04bacef0 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:27.830607  1126 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:27.831444  1126 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:27.831801   810 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:27.833225  1126 catalog_manager.cc:1383] Generated new cluster ID: 59789935d88d46a38e32d6c214dd120a
I20260812 06:18:27.833271  1126 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:27.847434  1126 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:27.847990  1126 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:27.853971  1126 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 1b1a88a7eaf246f0a1201c5f04bacef0: Generated new TSK 0
I20260812 06:18:27.854194  1126 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:27.864112   810 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:27.865965  1141 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:27.866103  1143 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:27.866127  1145 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:27.866475   810 server_base.cc:1061] running on GCE node
I20260812 06:18:27.866636   810 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:27.866686   810 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:27.866703   810 hybrid_clock.cc:648] HybridClock initialized: now 1786515507866703 us; error 0 us; skew 500 ppm
I20260812 06:18:27.867606   810 webserver.cc:533] Webserver started at http://127.0.202.129:41037/ using document root <none> and password file <none>
I20260812 06:18:27.867784   810 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:27.867834   810 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:27.867934   810 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:27.868323   810 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502530812-810-0/minicluster-data/ts-0-root/instance:
uuid: "54c1a210534e44f593a626cf54191b02"
format_stamp: "Formatted at 2026-08-12 06:18:27 on dist-test-slave-gp6n"
I20260812 06:18:27.869805   810 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:18:27.870808  1151 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:27.871066   810 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:18:27.871130   810 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502530812-810-0/minicluster-data/ts-0-root
uuid: "54c1a210534e44f593a626cf54191b02"
format_stamp: "Formatted at 2026-08-12 06:18:27 on dist-test-slave-gp6n"
I20260812 06:18:27.871220   810 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502530812-810-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502530812-810-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502530812-810-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:27.879958   810 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:27.880270   810 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:27.880558   810 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:27.880991   810 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:27.881028   810 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:27.881084   810 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:27.881124   810 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:27.885337   810 rpc_server.cc:307] RPC server started. Bound to: 127.0.202.129:33607
I20260812 06:18:27.885370  1223 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.0.202.129:33607 every 8 connection(s)
I20260812 06:18:27.893352  1224 heartbeater.cc:344] Connected to a master server at 127.0.202.190:39303
I20260812 06:18:27.893447  1224 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:27.893628  1224 heartbeater.cc:507] Master 127.0.202.190:39303 requested a full tablet report, sending...
I20260812 06:18:27.894217  1070 ts_manager.cc:194] Registered new tserver with Master: 54c1a210534e44f593a626cf54191b02 (127.0.202.129:33607)
I20260812 06:18:27.894681   810 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.008885814s
I20260812 06:18:27.895067  1070 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:54052
I20260812 06:18:27.901984  1070 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:54062:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:18:27.910210  1185 tablet_service.cc:1511] Processing CreateTablet for tablet 7f849897f6dd4a80a036824247264ebc (DEFAULT_TABLE table=heavy-update-compaction-test [id=3e8c29391ddc46e194e8d6f2b86a048b]), partition=
I20260812 06:18:27.910534  1185 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 7f849897f6dd4a80a036824247264ebc. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:27.912386  1237 tablet_bootstrap.cc:492] T 7f849897f6dd4a80a036824247264ebc P 54c1a210534e44f593a626cf54191b02: Bootstrap starting.
I20260812 06:18:27.913206  1237 tablet_bootstrap.cc:654] T 7f849897f6dd4a80a036824247264ebc P 54c1a210534e44f593a626cf54191b02: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:27.914220  1237 tablet_bootstrap.cc:492] T 7f849897f6dd4a80a036824247264ebc P 54c1a210534e44f593a626cf54191b02: No bootstrap required, opened a new log
I20260812 06:18:27.914291  1237 ts_tablet_manager.cc:1403] T 7f849897f6dd4a80a036824247264ebc P 54c1a210534e44f593a626cf54191b02: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:18:27.914822  1237 raft_consensus.cc:359] T 7f849897f6dd4a80a036824247264ebc P 54c1a210534e44f593a626cf54191b02 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "54c1a210534e44f593a626cf54191b02" member_type: VOTER last_known_addr { host: "127.0.202.129" port: 33607 } }
I20260812 06:18:27.914909  1237 raft_consensus.cc:385] T 7f849897f6dd4a80a036824247264ebc P 54c1a210534e44f593a626cf54191b02 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:27.914966  1237 raft_consensus.cc:740] T 7f849897f6dd4a80a036824247264ebc P 54c1a210534e44f593a626cf54191b02 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 54c1a210534e44f593a626cf54191b02, State: Initialized, Role: FOLLOWER
I20260812 06:18:27.915130  1237 consensus_queue.cc:260] T 7f849897f6dd4a80a036824247264ebc P 54c1a210534e44f593a626cf54191b02 [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: "54c1a210534e44f593a626cf54191b02" member_type: VOTER last_known_addr { host: "127.0.202.129" port: 33607 } }
I20260812 06:18:27.915225  1237 raft_consensus.cc:399] T 7f849897f6dd4a80a036824247264ebc P 54c1a210534e44f593a626cf54191b02 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:27.915271  1237 raft_consensus.cc:493] T 7f849897f6dd4a80a036824247264ebc P 54c1a210534e44f593a626cf54191b02 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:27.915324  1237 raft_consensus.cc:3060] T 7f849897f6dd4a80a036824247264ebc P 54c1a210534e44f593a626cf54191b02 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:27.916023  1237 raft_consensus.cc:515] T 7f849897f6dd4a80a036824247264ebc P 54c1a210534e44f593a626cf54191b02 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "54c1a210534e44f593a626cf54191b02" member_type: VOTER last_known_addr { host: "127.0.202.129" port: 33607 } }
I20260812 06:18:27.916193  1237 leader_election.cc:304] T 7f849897f6dd4a80a036824247264ebc P 54c1a210534e44f593a626cf54191b02 [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: 54c1a210534e44f593a626cf54191b02; no voters: 
I20260812 06:18:27.916394  1237 leader_election.cc:290] T 7f849897f6dd4a80a036824247264ebc P 54c1a210534e44f593a626cf54191b02 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:27.916525  1239 raft_consensus.cc:2804] T 7f849897f6dd4a80a036824247264ebc P 54c1a210534e44f593a626cf54191b02 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:27.916738  1237 ts_tablet_manager.cc:1434] T 7f849897f6dd4a80a036824247264ebc P 54c1a210534e44f593a626cf54191b02: Time spent starting tablet: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:18:27.916738  1239 raft_consensus.cc:697] T 7f849897f6dd4a80a036824247264ebc P 54c1a210534e44f593a626cf54191b02 [term 1 LEADER]: Becoming Leader. State: Replica: 54c1a210534e44f593a626cf54191b02, State: Running, Role: LEADER
I20260812 06:18:27.916738  1224 heartbeater.cc:499] Master 127.0.202.190:39303 was elected leader, sending a full tablet report...
I20260812 06:18:27.916958  1239 consensus_queue.cc:237] T 7f849897f6dd4a80a036824247264ebc P 54c1a210534e44f593a626cf54191b02 [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: "54c1a210534e44f593a626cf54191b02" member_type: VOTER last_known_addr { host: "127.0.202.129" port: 33607 } }
I20260812 06:18:27.918283  1070 catalog_manager.cc:5719] T 7f849897f6dd4a80a036824247264ebc P 54c1a210534e44f593a626cf54191b02 reported cstate change: term changed from 0 to 1, leader changed from <none> to 54c1a210534e44f593a626cf54191b02 (127.0.202.129). New cstate: current_term: 1 leader_uuid: "54c1a210534e44f593a626cf54191b02" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "54c1a210534e44f593a626cf54191b02" member_type: VOTER last_known_addr { host: "127.0.202.129" port: 33607 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:27.976215   810 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.050s	user 0.010s	sys 0.012s
I20260812 06:18:28.136291  1225 maintenance_manager.cc:419] P 54c1a210534e44f593a626cf54191b02: Scheduling FlushMRSOp(7f849897f6dd4a80a036824247264ebc): perf score=19.054940
I20260812 06:18:28.302110  1156 maintenance_manager.cc:643] P 54c1a210534e44f593a626cf54191b02: FlushMRSOp(7f849897f6dd4a80a036824247264ebc) complete. Timing: real 0.166s	user 0.130s	sys 0.032s Metrics: {"bytes_written":13004893,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":72,"dirs.run_cpu_time_us":218,"dirs.run_wall_time_us":1023,"drs_written":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4,"lbm_write_time_us":43887,"lbm_writes_lt_1ms":784,"mutex_wait_us":198,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"spinlock_wait_cycles":1664,"update_count":1585}
I20260812 06:18:28.302902  1225 maintenance_manager.cc:419] P 54c1a210534e44f593a626cf54191b02: Scheduling LogGCOp(7f849897f6dd4a80a036824247264ebc): free 20290830 bytes of WAL
I20260812 06:18:28.303154  1156 log_reader.cc:385] T 7f849897f6dd4a80a036824247264ebc: removed 2 log segments from log reader
I20260812 06:18:28.303243  1156 log.cc:1079] T 7f849897f6dd4a80a036824247264ebc P 54c1a210534e44f593a626cf54191b02: Deleting log segment in path: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502530812-810-0/minicluster-data/ts-0-root/wals/7f849897f6dd4a80a036824247264ebc/wal-000000001 (ops 1-6)
I20260812 06:18:28.303392  1156 log.cc:1079] T 7f849897f6dd4a80a036824247264ebc P 54c1a210534e44f593a626cf54191b02: Deleting log segment in path: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502530812-810-0/minicluster-data/ts-0-root/wals/7f849897f6dd4a80a036824247264ebc/wal-000000002 (ops 7-10)
I20260812 06:18:28.309465  1156 maintenance_manager.cc:643] P 54c1a210534e44f593a626cf54191b02: LogGCOp(7f849897f6dd4a80a036824247264ebc) complete. Timing: real 0.006s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:18:28.309942  1225 maintenance_manager.cc:419] P 54c1a210534e44f593a626cf54191b02: Scheduling FlushDeltaMemStoresOp(7f849897f6dd4a80a036824247264ebc): perf score=1.196750
I20260812 06:18:28.324236  1156 maintenance_manager.cc:643] P 54c1a210534e44f593a626cf54191b02: FlushDeltaMemStoresOp(7f849897f6dd4a80a036824247264ebc) complete. Timing: real 0.014s	user 0.004s	sys 0.004s Metrics: {"bytes_written":2994980,"delete_count":0,"lbm_write_time_us":3464,"lbm_writes_lt_1ms":76,"reinsert_count":0,"update_count":365}
I20260812 06:18:28.324637  1225 maintenance_manager.cc:419] P 54c1a210534e44f593a626cf54191b02: Scheduling FlushDeltaMemStoresOp(7f849897f6dd4a80a036824247264ebc): perf score=2.188937
I20260812 06:18:28.334818  1156 maintenance_manager.cc:643] P 54c1a210534e44f593a626cf54191b02: FlushDeltaMemStoresOp(7f849897f6dd4a80a036824247264ebc) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3968,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:28.335197  1225 maintenance_manager.cc:419] P 54c1a210534e44f593a626cf54191b02: Scheduling MajorDeltaCompactionOp(7f849897f6dd4a80a036824247264ebc): perf score=1.000000
I20260812 06:18:28.501760  1156 maintenance_manager.cc:643] P 54c1a210534e44f593a626cf54191b02: MajorDeltaCompactionOp(7f849897f6dd4a80a036824247264ebc) complete. Timing: real 0.166s	user 0.109s	sys 0.045s Metrics: {"cfile_cache_miss":523,"cfile_cache_miss_bytes":24405527,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":836,"lbm_read_time_us":11722,"lbm_reads_lt_1ms":563,"lbm_write_time_us":28361,"lbm_writes_lt_1ms":533,"peak_mem_usage":61665166,"reinsert_count":0,"spinlock_wait_cycles":7296,"thread_start_us":371,"threads_started":5,"update_count":2450}
I20260812 06:18:28.502470  1225 maintenance_manager.cc:419] P 54c1a210534e44f593a626cf54191b02: Scheduling FlushDeltaMemStoresOp(7f849897f6dd4a80a036824247264ebc): perf score=14.095187
I20260812 06:18:28.554217  1156 maintenance_manager.cc:643] P 54c1a210534e44f593a626cf54191b02: FlushDeltaMemStoresOp(7f849897f6dd4a80a036824247264ebc) complete. Timing: real 0.052s	user 0.026s	sys 0.017s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20766,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:28.554702  1225 maintenance_manager.cc:419] P 54c1a210534e44f593a626cf54191b02: Scheduling UndoDeltaBlockGCOp(7f849897f6dd4a80a036824247264ebc): 16821648 bytes on disk
I20260812 06:18:28.555087  1156 maintenance_manager.cc:643] P 54c1a210534e44f593a626cf54191b02: UndoDeltaBlockGCOp(7f849897f6dd4a80a036824247264ebc) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":47,"lbm_reads_lt_1ms":4}
I20260812 06:18:28.555464  1225 maintenance_manager.cc:419] P 54c1a210534e44f593a626cf54191b02: Scheduling FlushDeltaMemStoresOp(7f849897f6dd4a80a036824247264ebc): perf score=2.188937
I20260812 06:18:28.565714  1156 maintenance_manager.cc:643] P 54c1a210534e44f593a626cf54191b02: FlushDeltaMemStoresOp(7f849897f6dd4a80a036824247264ebc) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3866,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:28.566321  1225 maintenance_manager.cc:419] P 54c1a210534e44f593a626cf54191b02: Scheduling MajorDeltaCompactionOp(7f849897f6dd4a80a036824247264ebc): perf score=1.000000
I20260812 06:18:28.733747  1156 maintenance_manager.cc:643] P 54c1a210534e44f593a626cf54191b02: MajorDeltaCompactionOp(7f849897f6dd4a80a036824247264ebc) complete. Timing: real 0.166s	user 0.136s	sys 0.025s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":289,"lbm_read_time_us":10363,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32156,"lbm_writes_lt_1ms":543,"mutex_wait_us":47,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2500}
I20260812 06:18:28.734274  1225 maintenance_manager.cc:419] P 54c1a210534e44f593a626cf54191b02: Scheduling FlushDeltaMemStoresOp(7f849897f6dd4a80a036824247264ebc): perf score=14.095187
I20260812 06:18:28.776728  1156 maintenance_manager.cc:643] P 54c1a210534e44f593a626cf54191b02: FlushDeltaMemStoresOp(7f849897f6dd4a80a036824247264ebc) complete. Timing: real 0.042s	user 0.026s	sys 0.013s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":18836,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:28.777228  1225 maintenance_manager.cc:419] P 54c1a210534e44f593a626cf54191b02: Scheduling MajorDeltaCompactionOp(7f849897f6dd4a80a036824247264ebc): perf score=1.000000
I20260812 06:18:28.926451  1156 maintenance_manager.cc:643] P 54c1a210534e44f593a626cf54191b02: MajorDeltaCompactionOp(7f849897f6dd4a80a036824247264ebc) complete. Timing: real 0.149s	user 0.103s	sys 0.040s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713153,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":1137,"lbm_read_time_us":10562,"lbm_reads_lt_1ms":467,"lbm_write_time_us":23205,"lbm_writes_lt_1ms":443,"mutex_wait_us":283,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":20096,"update_count":2000}
I20260812 06:18:28.927058  1225 maintenance_manager.cc:419] P 54c1a210534e44f593a626cf54191b02: Scheduling FlushDeltaMemStoresOp(7f849897f6dd4a80a036824247264ebc): perf score=14.095187
I20260812 06:18:28.979915  1156 maintenance_manager.cc:643] P 54c1a210534e44f593a626cf54191b02: FlushDeltaMemStoresOp(7f849897f6dd4a80a036824247264ebc) complete. Timing: real 0.053s	user 0.036s	sys 0.008s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20488,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:28.980393  1225 maintenance_manager.cc:419] P 54c1a210534e44f593a626cf54191b02: Scheduling FlushDeltaMemStoresOp(7f849897f6dd4a80a036824247264ebc): perf score=2.188937
I20260812 06:18:28.991477  1156 maintenance_manager.cc:643] P 54c1a210534e44f593a626cf54191b02: FlushDeltaMemStoresOp(7f849897f6dd4a80a036824247264ebc) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4222,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:28.991922  1225 maintenance_manager.cc:419] P 54c1a210534e44f593a626cf54191b02: Scheduling MajorDeltaCompactionOp(7f849897f6dd4a80a036824247264ebc): perf score=1.000000
I20260812 06:18:29.177294  1156 maintenance_manager.cc:643] P 54c1a210534e44f593a626cf54191b02: MajorDeltaCompactionOp(7f849897f6dd4a80a036824247264ebc) complete. Timing: real 0.185s	user 0.107s	sys 0.074s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":325,"lbm_read_time_us":11957,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29545,"lbm_writes_lt_1ms":543,"mutex_wait_us":21,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10240,"update_count":2500}
I20260812 06:18:29.177883  1225 maintenance_manager.cc:419] P 54c1a210534e44f593a626cf54191b02: Scheduling FlushDeltaMemStoresOp(7f849897f6dd4a80a036824247264ebc): perf score=14.095187
I20260812 06:18:29.228340  1156 maintenance_manager.cc:643] P 54c1a210534e44f593a626cf54191b02: FlushDeltaMemStoresOp(7f849897f6dd4a80a036824247264ebc) complete. Timing: real 0.050s	user 0.028s	sys 0.016s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":19873,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:29.228842  1225 maintenance_manager.cc:419] P 54c1a210534e44f593a626cf54191b02: Scheduling FlushDeltaMemStoresOp(7f849897f6dd4a80a036824247264ebc): perf score=2.188937
I20260812 06:18:29.239692  1156 maintenance_manager.cc:643] P 54c1a210534e44f593a626cf54191b02: FlushDeltaMemStoresOp(7f849897f6dd4a80a036824247264ebc) complete. Timing: real 0.011s	user 0.009s	sys 0.000s 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:18:29.240157  1225 maintenance_manager.cc:419] P 54c1a210534e44f593a626cf54191b02: Scheduling MajorDeltaCompactionOp(7f849897f6dd4a80a036824247264ebc): perf score=1.000000
I20260812 06:18:29.393800  1156 maintenance_manager.cc:643] P 54c1a210534e44f593a626cf54191b02: MajorDeltaCompactionOp(7f849897f6dd4a80a036824247264ebc) complete. Timing: real 0.153s	user 0.127s	sys 0.024s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":727,"lbm_read_time_us":10257,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29756,"lbm_writes_lt_1ms":543,"mutex_wait_us":108,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7040,"update_count":2500}
I20260812 06:18:29.394730  1225 maintenance_manager.cc:419] P 54c1a210534e44f593a626cf54191b02: Scheduling FlushDeltaMemStoresOp(7f849897f6dd4a80a036824247264ebc): perf score=11.118625
I20260812 06:18:29.426229  1156 maintenance_manager.cc:643] P 54c1a210534e44f593a626cf54191b02: FlushDeltaMemStoresOp(7f849897f6dd4a80a036824247264ebc) complete. Timing: real 0.031s	user 0.028s	sys 0.000s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":13301,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:29.426836  1225 maintenance_manager.cc:419] P 54c1a210534e44f593a626cf54191b02: Scheduling FlushDeltaMemStoresOp(7f849897f6dd4a80a036824247264ebc): perf score=2.188937
I20260812 06:18:29.451773  1156 maintenance_manager.cc:643] P 54c1a210534e44f593a626cf54191b02: FlushDeltaMemStoresOp(7f849897f6dd4a80a036824247264ebc) complete. Timing: real 0.025s	user 0.006s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4346,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:29.452368  1225 maintenance_manager.cc:419] P 54c1a210534e44f593a626cf54191b02: Scheduling FlushDeltaMemStoresOp(7f849897f6dd4a80a036824247264ebc): perf score=2.188937
I20260812 06:18:29.462981  1156 maintenance_manager.cc:643] P 54c1a210534e44f593a626cf54191b02: FlushDeltaMemStoresOp(7f849897f6dd4a80a036824247264ebc) complete. Timing: real 0.010s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4223,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:29.463522  1225 maintenance_manager.cc:419] P 54c1a210534e44f593a626cf54191b02: Scheduling FlushMRSOp(7f849897f6dd4a80a036824247264ebc): perf score=1.000000
I20260812 06:18:29.490751  1156 maintenance_manager.cc:643] P 54c1a210534e44f593a626cf54191b02: FlushMRSOp(7f849897f6dd4a80a036824247264ebc) complete. Timing: real 0.027s	user 0.027s	sys 0.000s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":72,"dirs.run_cpu_time_us":250,"dirs.run_wall_time_us":1596,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1486,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:29.491354  1225 maintenance_manager.cc:419] P 54c1a210534e44f593a626cf54191b02: Scheduling LogGCOp(7f849897f6dd4a80a036824247264ebc): free 120553378 bytes of WAL
I20260812 06:18:29.491576  1156 log_reader.cc:385] T 7f849897f6dd4a80a036824247264ebc: removed 12 log segments from log reader
I20260812 06:18:29.491619  1156 log.cc:1079] T 7f849897f6dd4a80a036824247264ebc P 54c1a210534e44f593a626cf54191b02: Deleting log segment in path: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502530812-810-0/minicluster-data/ts-0-root/wals/7f849897f6dd4a80a036824247264ebc/wal-000000003 (ops 11-15)
I20260812 06:18:29.491648  1156 log.cc:1079] T 7f849897f6dd4a80a036824247264ebc P 54c1a210534e44f593a626cf54191b02: Deleting log segment in path: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502530812-810-0/minicluster-data/ts-0-root/wals/7f849897f6dd4a80a036824247264ebc/wal-000000004 (ops 16-20)
I20260812 06:18:29.491709  1156 log.cc:1079] T 7f849897f6dd4a80a036824247264ebc P 54c1a210534e44f593a626cf54191b02: Deleting log segment in path: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502530812-810-0/minicluster-data/ts-0-root/wals/7f849897f6dd4a80a036824247264ebc/wal-000000005 (ops 21-25)
I20260812 06:18:29.491743  1156 log.cc:1079] T 7f849897f6dd4a80a036824247264ebc P 54c1a210534e44f593a626cf54191b02: Deleting log segment in path: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502530812-810-0/minicluster-data/ts-0-root/wals/7f849897f6dd4a80a036824247264ebc/wal-000000006 (ops 26-30)
I20260812 06:18:29.491786  1156 log.cc:1079] T 7f849897f6dd4a80a036824247264ebc P 54c1a210534e44f593a626cf54191b02: Deleting log segment in path: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502530812-810-0/minicluster-data/ts-0-root/wals/7f849897f6dd4a80a036824247264ebc/wal-000000007 (ops 31-35)
I20260812 06:18:29.491830  1156 log.cc:1079] T 7f849897f6dd4a80a036824247264ebc P 54c1a210534e44f593a626cf54191b02: Deleting log segment in path: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502530812-810-0/minicluster-data/ts-0-root/wals/7f849897f6dd4a80a036824247264ebc/wal-000000008 (ops 36-40)
I20260812 06:18:29.491869  1156 log.cc:1079] T 7f849897f6dd4a80a036824247264ebc P 54c1a210534e44f593a626cf54191b02: Deleting log segment in path: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502530812-810-0/minicluster-data/ts-0-root/wals/7f849897f6dd4a80a036824247264ebc/wal-000000009 (ops 41-44)
I20260812 06:18:29.491910  1156 log.cc:1079] T 7f849897f6dd4a80a036824247264ebc P 54c1a210534e44f593a626cf54191b02: Deleting log segment in path: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502530812-810-0/minicluster-data/ts-0-root/wals/7f849897f6dd4a80a036824247264ebc/wal-000000010 (ops 45-49)
I20260812 06:18:29.491952  1156 log.cc:1079] T 7f849897f6dd4a80a036824247264ebc P 54c1a210534e44f593a626cf54191b02: Deleting log segment in path: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502530812-810-0/minicluster-data/ts-0-root/wals/7f849897f6dd4a80a036824247264ebc/wal-000000011 (ops 50-54)
I20260812 06:18:29.491991  1156 log.cc:1079] T 7f849897f6dd4a80a036824247264ebc P 54c1a210534e44f593a626cf54191b02: Deleting log segment in path: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502530812-810-0/minicluster-data/ts-0-root/wals/7f849897f6dd4a80a036824247264ebc/wal-000000012 (ops 55-59)
I20260812 06:18:29.492031  1156 log.cc:1079] T 7f849897f6dd4a80a036824247264ebc P 54c1a210534e44f593a626cf54191b02: Deleting log segment in path: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502530812-810-0/minicluster-data/ts-0-root/wals/7f849897f6dd4a80a036824247264ebc/wal-000000013 (ops 60-64)
I20260812 06:18:29.492070  1156 log.cc:1079] T 7f849897f6dd4a80a036824247264ebc P 54c1a210534e44f593a626cf54191b02: Deleting log segment in path: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502530812-810-0/minicluster-data/ts-0-root/wals/7f849897f6dd4a80a036824247264ebc/wal-000000014 (ops 65-68)
I20260812 06:18:29.516738  1156 maintenance_manager.cc:643] P 54c1a210534e44f593a626cf54191b02: LogGCOp(7f849897f6dd4a80a036824247264ebc) complete. Timing: real 0.025s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:18:29.517230  1225 maintenance_manager.cc:419] P 54c1a210534e44f593a626cf54191b02: Scheduling UndoDeltaBlockGCOp(7f849897f6dd4a80a036824247264ebc): 447 bytes on disk
I20260812 06:18:29.517722  1156 maintenance_manager.cc:643] P 54c1a210534e44f593a626cf54191b02: UndoDeltaBlockGCOp(7f849897f6dd4a80a036824247264ebc) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":68,"lbm_reads_lt_1ms":4}
I20260812 06:18:29.518296  1225 maintenance_manager.cc:419] P 54c1a210534e44f593a626cf54191b02: Scheduling FlushDeltaMemStoresOp(7f849897f6dd4a80a036824247264ebc): perf score=3.181125
I20260812 06:18:29.541043  1156 maintenance_manager.cc:643] P 54c1a210534e44f593a626cf54191b02: FlushDeltaMemStoresOp(7f849897f6dd4a80a036824247264ebc) complete. Timing: real 0.023s	user 0.002s	sys 0.017s Metrics: {"bytes_written":4512902,"delete_count":0,"lbm_write_time_us":4467,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:29.541487  1225 maintenance_manager.cc:419] P 54c1a210534e44f593a626cf54191b02: Scheduling FlushDeltaMemStoresOp(7f849897f6dd4a80a036824247264ebc): perf score=2.188937
I20260812 06:18:29.551453  1156 maintenance_manager.cc:643] P 54c1a210534e44f593a626cf54191b02: FlushDeltaMemStoresOp(7f849897f6dd4a80a036824247264ebc) complete. Timing: real 0.010s	user 0.008s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3631,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:29.551856  1225 maintenance_manager.cc:419] P 54c1a210534e44f593a626cf54191b02: Scheduling MajorDeltaCompactionOp(7f849897f6dd4a80a036824247264ebc): perf score=1.000000
I20260812 06:18:29.786238  1156 maintenance_manager.cc:643] P 54c1a210534e44f593a626cf54191b02: MajorDeltaCompactionOp(7f849897f6dd4a80a036824247264ebc) complete. Timing: real 0.234s	user 0.176s	sys 0.058s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":33020843,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":181,"lbm_read_time_us":16479,"lbm_reads_lt_1ms":775,"lbm_write_time_us":40826,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":39936,"thread_start_us":76,"threads_started":1,"update_count":3500}
I20260812 06:18:29.786770  1225 maintenance_manager.cc:419] P 54c1a210534e44f593a626cf54191b02: Scheduling FlushDeltaMemStoresOp(7f849897f6dd4a80a036824247264ebc): perf score=14.095187
I20260812 06:18:29.842199  1156 maintenance_manager.cc:643] P 54c1a210534e44f593a626cf54191b02: FlushDeltaMemStoresOp(7f849897f6dd4a80a036824247264ebc) complete. Timing: real 0.055s	user 0.029s	sys 0.015s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21908,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:29.842859  1225 maintenance_manager.cc:419] P 54c1a210534e44f593a626cf54191b02: Scheduling FlushDeltaMemStoresOp(7f849897f6dd4a80a036824247264ebc): perf score=2.188937
I20260812 06:18:29.854050  1156 maintenance_manager.cc:643] P 54c1a210534e44f593a626cf54191b02: FlushDeltaMemStoresOp(7f849897f6dd4a80a036824247264ebc) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4437,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:29.854604  1225 maintenance_manager.cc:419] P 54c1a210534e44f593a626cf54191b02: Scheduling MajorDeltaCompactionOp(7f849897f6dd4a80a036824247264ebc): perf score=1.000000
I20260812 06:18:30.035830  1156 maintenance_manager.cc:643] P 54c1a210534e44f593a626cf54191b02: MajorDeltaCompactionOp(7f849897f6dd4a80a036824247264ebc) complete. Timing: real 0.181s	user 0.124s	sys 0.053s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":797,"lbm_read_time_us":14527,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29189,"lbm_writes_lt_1ms":543,"mutex_wait_us":68,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7040,"update_count":2500}
I20260812 06:18:30.036486  1225 maintenance_manager.cc:419] P 54c1a210534e44f593a626cf54191b02: Scheduling FlushDeltaMemStoresOp(7f849897f6dd4a80a036824247264ebc): perf score=14.095187
I20260812 06:18:30.094043  1156 maintenance_manager.cc:643] P 54c1a210534e44f593a626cf54191b02: FlushDeltaMemStoresOp(7f849897f6dd4a80a036824247264ebc) complete. Timing: real 0.057s	user 0.035s	sys 0.019s Metrics: {"bytes_written":16409898,"delete_count":0,"lbm_write_time_us":21279,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:30.094605  1225 maintenance_manager.cc:419] P 54c1a210534e44f593a626cf54191b02: Scheduling FlushDeltaMemStoresOp(7f849897f6dd4a80a036824247264ebc): perf score=2.188937
I20260812 06:18:30.105582  1156 maintenance_manager.cc:643] P 54c1a210534e44f593a626cf54191b02: FlushDeltaMemStoresOp(7f849897f6dd4a80a036824247264ebc) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4391,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:30.106029  1225 maintenance_manager.cc:419] P 54c1a210534e44f593a626cf54191b02: Scheduling MajorDeltaCompactionOp(7f849897f6dd4a80a036824247264ebc): perf score=1.000000
I20260812 06:18:30.288216  1156 maintenance_manager.cc:643] P 54c1a210534e44f593a626cf54191b02: MajorDeltaCompactionOp(7f849897f6dd4a80a036824247264ebc) complete. Timing: real 0.182s	user 0.112s	sys 0.067s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815680,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1533,"lbm_read_time_us":13069,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30065,"lbm_writes_lt_1ms":543,"mutex_wait_us":526,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5376,"update_count":2500}
I20260812 06:18:30.288805  1225 maintenance_manager.cc:419] P 54c1a210534e44f593a626cf54191b02: Scheduling FlushDeltaMemStoresOp(7f849897f6dd4a80a036824247264ebc): perf score=11.118625
I20260812 06:18:30.325961  1156 maintenance_manager.cc:643] P 54c1a210534e44f593a626cf54191b02: FlushDeltaMemStoresOp(7f849897f6dd4a80a036824247264ebc) complete. Timing: real 0.037s	user 0.021s	sys 0.012s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":16132,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:30.326707  1225 maintenance_manager.cc:419] P 54c1a210534e44f593a626cf54191b02: Scheduling FlushDeltaMemStoresOp(7f849897f6dd4a80a036824247264ebc): perf score=2.188937
I20260812 06:18:30.352288  1156 maintenance_manager.cc:643] P 54c1a210534e44f593a626cf54191b02: FlushDeltaMemStoresOp(7f849897f6dd4a80a036824247264ebc) complete. Timing: real 0.025s	user 0.009s	sys 0.012s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6248,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:30.353406  1225 maintenance_manager.cc:419] P 54c1a210534e44f593a626cf54191b02: Scheduling FlushDeltaMemStoresOp(7f849897f6dd4a80a036824247264ebc): perf score=1.000000
I20260812 06:18:30.363103  1156 maintenance_manager.cc:643] P 54c1a210534e44f593a626cf54191b02: FlushDeltaMemStoresOp(7f849897f6dd4a80a036824247264ebc) complete. Timing: real 0.010s	user 0.003s	sys 0.001s Metrics: {"bytes_written":1271931,"delete_count":0,"lbm_write_time_us":1213,"lbm_writes_lt_1ms":34,"reinsert_count":0,"update_count":155}
I20260812 06:18:30.363560  1225 maintenance_manager.cc:419] P 54c1a210534e44f593a626cf54191b02: Scheduling FlushDeltaMemStoresOp(7f849897f6dd4a80a036824247264ebc): perf score=1.196750
I20260812 06:18:30.371305  1156 maintenance_manager.cc:643] P 54c1a210534e44f593a626cf54191b02: FlushDeltaMemStoresOp(7f849897f6dd4a80a036824247264ebc) complete. Timing: real 0.008s	user 0.000s	sys 0.007s Metrics: {"bytes_written":2830880,"delete_count":0,"lbm_write_time_us":2892,"lbm_writes_lt_1ms":72,"reinsert_count":0,"update_count":345}
I20260812 06:18:30.371748  1225 maintenance_manager.cc:419] P 54c1a210534e44f593a626cf54191b02: Scheduling MajorDeltaCompactionOp(7f849897f6dd4a80a036824247264ebc): perf score=1.000000
I20260812 06:18:30.555184  1156 maintenance_manager.cc:643] P 54c1a210534e44f593a626cf54191b02: MajorDeltaCompactionOp(7f849897f6dd4a80a036824247264ebc) complete. Timing: real 0.183s	user 0.100s	sys 0.078s Metrics: {"cfile_cache_miss":534,"cfile_cache_miss_bytes":24815821,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":342,"lbm_read_time_us":12766,"lbm_reads_lt_1ms":574,"lbm_write_time_us":29407,"lbm_writes_lt_1ms":543,"mutex_wait_us":45,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:18:30.555737  1225 maintenance_manager.cc:419] P 54c1a210534e44f593a626cf54191b02: Scheduling FlushDeltaMemStoresOp(7f849897f6dd4a80a036824247264ebc): perf score=14.095187
I20260812 06:18:30.602370  1156 maintenance_manager.cc:643] P 54c1a210534e44f593a626cf54191b02: FlushDeltaMemStoresOp(7f849897f6dd4a80a036824247264ebc) complete. Timing: real 0.046s	user 0.020s	sys 0.022s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20129,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:30.602926  1225 maintenance_manager.cc:419] P 54c1a210534e44f593a626cf54191b02: Scheduling FlushDeltaMemStoresOp(7f849897f6dd4a80a036824247264ebc): perf score=2.188937
I20260812 06:18:30.629151  1156 maintenance_manager.cc:643] P 54c1a210534e44f593a626cf54191b02: FlushDeltaMemStoresOp(7f849897f6dd4a80a036824247264ebc) complete. Timing: real 0.026s	user 0.003s	sys 0.020s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5767,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:30.629768  1225 maintenance_manager.cc:419] P 54c1a210534e44f593a626cf54191b02: Scheduling MajorDeltaCompactionOp(7f849897f6dd4a80a036824247264ebc): perf score=1.000000
I20260812 06:18:30.799217  1156 maintenance_manager.cc:643] P 54c1a210534e44f593a626cf54191b02: MajorDeltaCompactionOp(7f849897f6dd4a80a036824247264ebc) complete. Timing: real 0.169s	user 0.112s	sys 0.057s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":150,"lbm_read_time_us":10824,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29470,"lbm_writes_lt_1ms":543,"mutex_wait_us":23,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7808,"update_count":2500}
I20260812 06:18:30.799911  1225 maintenance_manager.cc:419] P 54c1a210534e44f593a626cf54191b02: Scheduling FlushDeltaMemStoresOp(7f849897f6dd4a80a036824247264ebc): perf score=14.095187
I20260812 06:18:30.849160  1156 maintenance_manager.cc:643] P 54c1a210534e44f593a626cf54191b02: FlushDeltaMemStoresOp(7f849897f6dd4a80a036824247264ebc) complete. Timing: real 0.049s	user 0.028s	sys 0.015s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20463,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:30.849690  1225 maintenance_manager.cc:419] P 54c1a210534e44f593a626cf54191b02: Scheduling FlushDeltaMemStoresOp(7f849897f6dd4a80a036824247264ebc): perf score=2.188937
I20260812 06:18:30.861676  1156 maintenance_manager.cc:643] P 54c1a210534e44f593a626cf54191b02: FlushDeltaMemStoresOp(7f849897f6dd4a80a036824247264ebc) complete. Timing: real 0.012s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4066,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:30.862303  1225 maintenance_manager.cc:419] P 54c1a210534e44f593a626cf54191b02: Scheduling MajorDeltaCompactionOp(7f849897f6dd4a80a036824247264ebc): perf score=1.000000
I20260812 06:18:31.045403  1156 maintenance_manager.cc:643] P 54c1a210534e44f593a626cf54191b02: MajorDeltaCompactionOp(7f849897f6dd4a80a036824247264ebc) complete. Timing: real 0.183s	user 0.123s	sys 0.049s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":617,"lbm_read_time_us":11514,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28327,"lbm_writes_lt_1ms":543,"mutex_wait_us":61,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7808,"update_count":2500}
I20260812 06:18:31.046201  1225 maintenance_manager.cc:419] P 54c1a210534e44f593a626cf54191b02: Scheduling FlushDeltaMemStoresOp(7f849897f6dd4a80a036824247264ebc): perf score=14.095187
I20260812 06:18:31.097615  1156 maintenance_manager.cc:643] P 54c1a210534e44f593a626cf54191b02: FlushDeltaMemStoresOp(7f849897f6dd4a80a036824247264ebc) complete. Timing: real 0.051s	user 0.036s	sys 0.004s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":18986,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:31.098217  1225 maintenance_manager.cc:419] P 54c1a210534e44f593a626cf54191b02: Scheduling FlushDeltaMemStoresOp(7f849897f6dd4a80a036824247264ebc): perf score=2.188937
I20260812 06:18:31.109666  1156 maintenance_manager.cc:643] P 54c1a210534e44f593a626cf54191b02: FlushDeltaMemStoresOp(7f849897f6dd4a80a036824247264ebc) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4156,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:31.110671  1225 maintenance_manager.cc:419] P 54c1a210534e44f593a626cf54191b02: Scheduling FlushMRSOp(7f849897f6dd4a80a036824247264ebc): perf score=1.000000
I20260812 06:18:31.141139  1156 maintenance_manager.cc:643] P 54c1a210534e44f593a626cf54191b02: FlushMRSOp(7f849897f6dd4a80a036824247264ebc) complete. Timing: real 0.030s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":69,"dirs.run_cpu_time_us":238,"dirs.run_wall_time_us":1830,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1685,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:18:31.141768  1225 maintenance_manager.cc:419] P 54c1a210534e44f593a626cf54191b02: Scheduling LogGCOp(7f849897f6dd4a80a036824247264ebc): free 128867462 bytes of WAL
I20260812 06:18:31.141986  1156 log_reader.cc:385] T 7f849897f6dd4a80a036824247264ebc: removed 13 log segments from log reader
I20260812 06:18:31.142046  1156 log.cc:1079] T 7f849897f6dd4a80a036824247264ebc P 54c1a210534e44f593a626cf54191b02: Deleting log segment in path: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502530812-810-0/minicluster-data/ts-0-root/wals/7f849897f6dd4a80a036824247264ebc/wal-000000015 (ops 69-73)
I20260812 06:18:31.142099  1156 log.cc:1079] T 7f849897f6dd4a80a036824247264ebc P 54c1a210534e44f593a626cf54191b02: Deleting log segment in path: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502530812-810-0/minicluster-data/ts-0-root/wals/7f849897f6dd4a80a036824247264ebc/wal-000000016 (ops 74-78)
I20260812 06:18:31.142156  1156 log.cc:1079] T 7f849897f6dd4a80a036824247264ebc P 54c1a210534e44f593a626cf54191b02: Deleting log segment in path: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502530812-810-0/minicluster-data/ts-0-root/wals/7f849897f6dd4a80a036824247264ebc/wal-000000017 (ops 79-82)
I20260812 06:18:31.142197  1156 log.cc:1079] T 7f849897f6dd4a80a036824247264ebc P 54c1a210534e44f593a626cf54191b02: Deleting log segment in path: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502530812-810-0/minicluster-data/ts-0-root/wals/7f849897f6dd4a80a036824247264ebc/wal-000000018 (ops 83-87)
I20260812 06:18:31.142232  1156 log.cc:1079] T 7f849897f6dd4a80a036824247264ebc P 54c1a210534e44f593a626cf54191b02: Deleting log segment in path: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502530812-810-0/minicluster-data/ts-0-root/wals/7f849897f6dd4a80a036824247264ebc/wal-000000019 (ops 88-92)
I20260812 06:18:31.142270  1156 log.cc:1079] T 7f849897f6dd4a80a036824247264ebc P 54c1a210534e44f593a626cf54191b02: Deleting log segment in path: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502530812-810-0/minicluster-data/ts-0-root/wals/7f849897f6dd4a80a036824247264ebc/wal-000000020 (ops 93-96)
I20260812 06:18:31.142305  1156 log.cc:1079] T 7f849897f6dd4a80a036824247264ebc P 54c1a210534e44f593a626cf54191b02: Deleting log segment in path: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502530812-810-0/minicluster-data/ts-0-root/wals/7f849897f6dd4a80a036824247264ebc/wal-000000021 (ops 97-101)
I20260812 06:18:31.142350  1156 log.cc:1079] T 7f849897f6dd4a80a036824247264ebc P 54c1a210534e44f593a626cf54191b02: Deleting log segment in path: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502530812-810-0/minicluster-data/ts-0-root/wals/7f849897f6dd4a80a036824247264ebc/wal-000000022 (ops 102-106)
I20260812 06:18:31.142387  1156 log.cc:1079] T 7f849897f6dd4a80a036824247264ebc P 54c1a210534e44f593a626cf54191b02: Deleting log segment in path: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502530812-810-0/minicluster-data/ts-0-root/wals/7f849897f6dd4a80a036824247264ebc/wal-000000023 (ops 107-110)
I20260812 06:18:31.142453  1156 log.cc:1079] T 7f849897f6dd4a80a036824247264ebc P 54c1a210534e44f593a626cf54191b02: Deleting log segment in path: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502530812-810-0/minicluster-data/ts-0-root/wals/7f849897f6dd4a80a036824247264ebc/wal-000000024 (ops 111-115)
I20260812 06:18:31.142491  1156 log.cc:1079] T 7f849897f6dd4a80a036824247264ebc P 54c1a210534e44f593a626cf54191b02: Deleting log segment in path: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502530812-810-0/minicluster-data/ts-0-root/wals/7f849897f6dd4a80a036824247264ebc/wal-000000025 (ops 116-120)
I20260812 06:18:31.142529  1156 log.cc:1079] T 7f849897f6dd4a80a036824247264ebc P 54c1a210534e44f593a626cf54191b02: Deleting log segment in path: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502530812-810-0/minicluster-data/ts-0-root/wals/7f849897f6dd4a80a036824247264ebc/wal-000000026 (ops 121-125)
I20260812 06:18:31.142565  1156 log.cc:1079] T 7f849897f6dd4a80a036824247264ebc P 54c1a210534e44f593a626cf54191b02: Deleting log segment in path: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502530812-810-0/minicluster-data/ts-0-root/wals/7f849897f6dd4a80a036824247264ebc/wal-000000027 (ops 126-130)
I20260812 06:18:31.171154  1156 maintenance_manager.cc:643] P 54c1a210534e44f593a626cf54191b02: LogGCOp(7f849897f6dd4a80a036824247264ebc) complete. Timing: real 0.029s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:18:31.171679  1225 maintenance_manager.cc:419] P 54c1a210534e44f593a626cf54191b02: Scheduling FlushDeltaMemStoresOp(7f849897f6dd4a80a036824247264ebc): perf score=6.157687
I20260812 06:18:31.193739  1156 maintenance_manager.cc:643] P 54c1a210534e44f593a626cf54191b02: FlushDeltaMemStoresOp(7f849897f6dd4a80a036824247264ebc) complete. Timing: real 0.021s	user 0.009s	sys 0.010s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":9539,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:18:31.194190  1225 maintenance_manager.cc:419] P 54c1a210534e44f593a626cf54191b02: Scheduling UndoDeltaBlockGCOp(7f849897f6dd4a80a036824247264ebc): 492 bytes on disk
I20260812 06:18:31.194746  1156 maintenance_manager.cc:643] P 54c1a210534e44f593a626cf54191b02: UndoDeltaBlockGCOp(7f849897f6dd4a80a036824247264ebc) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":104,"lbm_reads_lt_1ms":4}
I20260812 06:18:31.195289  1225 maintenance_manager.cc:419] P 54c1a210534e44f593a626cf54191b02: Scheduling MajorDeltaCompactionOp(7f849897f6dd4a80a036824247264ebc): perf score=1.000000
I20260812 06:18:31.424497  1156 maintenance_manager.cc:643] P 54c1a210534e44f593a626cf54191b02: MajorDeltaCompactionOp(7f849897f6dd4a80a036824247264ebc) complete. Timing: real 0.229s	user 0.153s	sys 0.074s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":33020629,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":114,"lbm_read_time_us":15609,"lbm_reads_lt_1ms":769,"lbm_write_time_us":39297,"lbm_writes_lt_1ms":743,"mutex_wait_us":26,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":13312,"thread_start_us":80,"threads_started":1,"update_count":3500}
I20260812 06:18:31.425323  1225 maintenance_manager.cc:419] P 54c1a210534e44f593a626cf54191b02: Scheduling FlushDeltaMemStoresOp(7f849897f6dd4a80a036824247264ebc): perf score=18.063937
I20260812 06:18:31.495137  1156 maintenance_manager.cc:643] P 54c1a210534e44f593a626cf54191b02: FlushDeltaMemStoresOp(7f849897f6dd4a80a036824247264ebc) complete. Timing: real 0.069s	user 0.031s	sys 0.028s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":27162,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:31.495642  1225 maintenance_manager.cc:419] P 54c1a210534e44f593a626cf54191b02: Scheduling FlushDeltaMemStoresOp(7f849897f6dd4a80a036824247264ebc): perf score=2.188937
I20260812 06:18:31.507279  1156 maintenance_manager.cc:643] P 54c1a210534e44f593a626cf54191b02: FlushDeltaMemStoresOp(7f849897f6dd4a80a036824247264ebc) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3896,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:31.507778  1225 maintenance_manager.cc:419] P 54c1a210534e44f593a626cf54191b02: Scheduling MajorDeltaCompactionOp(7f849897f6dd4a80a036824247264ebc): perf score=1.000000
I20260812 06:18:31.716367  1156 maintenance_manager.cc:643] P 54c1a210534e44f593a626cf54191b02: MajorDeltaCompactionOp(7f849897f6dd4a80a036824247264ebc) complete. Timing: real 0.208s	user 0.121s	sys 0.080s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918099,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":222,"lbm_read_time_us":14863,"lbm_reads_lt_1ms":672,"lbm_write_time_us":34186,"lbm_writes_lt_1ms":643,"mutex_wait_us":93,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":3000}
I20260812 06:18:31.717144  1225 maintenance_manager.cc:419] P 54c1a210534e44f593a626cf54191b02: Scheduling FlushDeltaMemStoresOp(7f849897f6dd4a80a036824247264ebc): perf score=16.079562
I20260812 06:18:31.762521  1156 maintenance_manager.cc:643] P 54c1a210534e44f593a626cf54191b02: FlushDeltaMemStoresOp(7f849897f6dd4a80a036824247264ebc) complete. Timing: real 0.045s	user 0.041s	sys 0.004s Metrics: {"bytes_written":17845750,"delete_count":0,"lbm_write_time_us":19787,"lbm_writes_lt_1ms":438,"reinsert_count":0,"update_count":2175}
I20260812 06:18:31.763202  1225 maintenance_manager.cc:419] P 54c1a210534e44f593a626cf54191b02: Scheduling FlushDeltaMemStoresOp(7f849897f6dd4a80a036824247264ebc): perf score=1.196750
I20260812 06:18:31.782927  1156 maintenance_manager.cc:643] P 54c1a210534e44f593a626cf54191b02: FlushDeltaMemStoresOp(7f849897f6dd4a80a036824247264ebc) complete. Timing: real 0.020s	user 0.006s	sys 0.003s Metrics: {"bytes_written":3077034,"delete_count":0,"lbm_write_time_us":3475,"lbm_writes_lt_1ms":78,"reinsert_count":0,"update_count":375}
I20260812 06:18:31.783354  1225 maintenance_manager.cc:419] P 54c1a210534e44f593a626cf54191b02: Scheduling FlushDeltaMemStoresOp(7f849897f6dd4a80a036824247264ebc): perf score=2.188937
I20260812 06:18:31.792631  1156 maintenance_manager.cc:643] P 54c1a210534e44f593a626cf54191b02: FlushDeltaMemStoresOp(7f849897f6dd4a80a036824247264ebc) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3590,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:31.793032  1225 maintenance_manager.cc:419] P 54c1a210534e44f593a626cf54191b02: Scheduling MajorDeltaCompactionOp(7f849897f6dd4a80a036824247264ebc): perf score=1.000000
I20260812 06:18:31.986471  1156 maintenance_manager.cc:643] P 54c1a210534e44f593a626cf54191b02: MajorDeltaCompactionOp(7f849897f6dd4a80a036824247264ebc) complete. Timing: real 0.193s	user 0.146s	sys 0.047s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918184,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":869,"lbm_read_time_us":12336,"lbm_reads_lt_1ms":673,"lbm_write_time_us":32118,"lbm_writes_lt_1ms":643,"mutex_wait_us":111,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2432,"update_count":3000}
I20260812 06:18:31.987174  1225 maintenance_manager.cc:419] P 54c1a210534e44f593a626cf54191b02: Scheduling FlushDeltaMemStoresOp(7f849897f6dd4a80a036824247264ebc): perf score=14.095187
I20260812 06:18:32.048040  1156 maintenance_manager.cc:643] P 54c1a210534e44f593a626cf54191b02: FlushDeltaMemStoresOp(7f849897f6dd4a80a036824247264ebc) complete. Timing: real 0.061s	user 0.026s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21316,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:32.048585  1225 maintenance_manager.cc:419] P 54c1a210534e44f593a626cf54191b02: Scheduling FlushDeltaMemStoresOp(7f849897f6dd4a80a036824247264ebc): perf score=2.188937
I20260812 06:18:32.060506  1156 maintenance_manager.cc:643] P 54c1a210534e44f593a626cf54191b02: FlushDeltaMemStoresOp(7f849897f6dd4a80a036824247264ebc) complete. Timing: real 0.012s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4282,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:32.060992  1225 maintenance_manager.cc:419] P 54c1a210534e44f593a626cf54191b02: Scheduling MajorDeltaCompactionOp(7f849897f6dd4a80a036824247264ebc): perf score=1.000000
I20260812 06:18:32.254089  1156 maintenance_manager.cc:643] P 54c1a210534e44f593a626cf54191b02: MajorDeltaCompactionOp(7f849897f6dd4a80a036824247264ebc) complete. Timing: real 0.193s	user 0.105s	sys 0.084s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1182,"lbm_read_time_us":14340,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33298,"lbm_writes_lt_1ms":543,"mutex_wait_us":298,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13184,"update_count":2500}
I20260812 06:18:32.254951  1225 maintenance_manager.cc:419] P 54c1a210534e44f593a626cf54191b02: Scheduling FlushDeltaMemStoresOp(7f849897f6dd4a80a036824247264ebc): perf score=14.095187
I20260812 06:18:32.311568  1156 maintenance_manager.cc:643] P 54c1a210534e44f593a626cf54191b02: FlushDeltaMemStoresOp(7f849897f6dd4a80a036824247264ebc) complete. Timing: real 0.056s	user 0.025s	sys 0.031s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21021,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:32.312203  1225 maintenance_manager.cc:419] P 54c1a210534e44f593a626cf54191b02: Scheduling FlushDeltaMemStoresOp(7f849897f6dd4a80a036824247264ebc): perf score=2.188937
I20260812 06:18:32.323136  1156 maintenance_manager.cc:643] P 54c1a210534e44f593a626cf54191b02: FlushDeltaMemStoresOp(7f849897f6dd4a80a036824247264ebc) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4194,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:32.323735  1225 maintenance_manager.cc:419] P 54c1a210534e44f593a626cf54191b02: Scheduling MajorDeltaCompactionOp(7f849897f6dd4a80a036824247264ebc): perf score=1.000000
I20260812 06:18:32.507189  1156 maintenance_manager.cc:643] P 54c1a210534e44f593a626cf54191b02: MajorDeltaCompactionOp(7f849897f6dd4a80a036824247264ebc) complete. Timing: real 0.183s	user 0.112s	sys 0.068s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":824,"lbm_read_time_us":13265,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30797,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4096,"update_count":2500}
I20260812 06:18:32.507754  1225 maintenance_manager.cc:419] P 54c1a210534e44f593a626cf54191b02: Scheduling FlushDeltaMemStoresOp(7f849897f6dd4a80a036824247264ebc): perf score=14.095187
I20260812 06:18:32.568143  1156 maintenance_manager.cc:643] P 54c1a210534e44f593a626cf54191b02: FlushDeltaMemStoresOp(7f849897f6dd4a80a036824247264ebc) complete. Timing: real 0.060s	user 0.028s	sys 0.028s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":22235,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:32.568604  1225 maintenance_manager.cc:419] P 54c1a210534e44f593a626cf54191b02: Scheduling FlushDeltaMemStoresOp(7f849897f6dd4a80a036824247264ebc): perf score=2.188937
I20260812 06:18:32.579289  1156 maintenance_manager.cc:643] P 54c1a210534e44f593a626cf54191b02: FlushDeltaMemStoresOp(7f849897f6dd4a80a036824247264ebc) complete. Timing: real 0.011s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4168,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:32.579759  1225 maintenance_manager.cc:419] P 54c1a210534e44f593a626cf54191b02: Scheduling FlushMRSOp(7f849897f6dd4a80a036824247264ebc): perf score=1.000000
I20260812 06:18:32.618927  1156 maintenance_manager.cc:643] P 54c1a210534e44f593a626cf54191b02: FlushMRSOp(7f849897f6dd4a80a036824247264ebc) complete. Timing: real 0.039s	user 0.032s	sys 0.002s Metrics: {"bytes_written":1193507,"cfile_init":1,"dirs.queue_time_us":57,"dirs.run_cpu_time_us":235,"dirs.run_wall_time_us":1391,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1380,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:18:32.619722  1225 maintenance_manager.cc:419] P 54c1a210534e44f593a626cf54191b02: Scheduling LogGCOp(7f849897f6dd4a80a036824247264ebc): free 121006699 bytes of WAL
I20260812 06:18:32.619978  1156 log_reader.cc:385] T 7f849897f6dd4a80a036824247264ebc: removed 12 log segments from log reader
I20260812 06:18:32.620051  1156 log.cc:1079] T 7f849897f6dd4a80a036824247264ebc P 54c1a210534e44f593a626cf54191b02: Deleting log segment in path: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502530812-810-0/minicluster-data/ts-0-root/wals/7f849897f6dd4a80a036824247264ebc/wal-000000028 (ops 131-135)
I20260812 06:18:32.620105  1156 log.cc:1079] T 7f849897f6dd4a80a036824247264ebc P 54c1a210534e44f593a626cf54191b02: Deleting log segment in path: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502530812-810-0/minicluster-data/ts-0-root/wals/7f849897f6dd4a80a036824247264ebc/wal-000000029 (ops 136-140)
I20260812 06:18:32.620164  1156 log.cc:1079] T 7f849897f6dd4a80a036824247264ebc P 54c1a210534e44f593a626cf54191b02: Deleting log segment in path: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502530812-810-0/minicluster-data/ts-0-root/wals/7f849897f6dd4a80a036824247264ebc/wal-000000030 (ops 141-145)
I20260812 06:18:32.620208  1156 log.cc:1079] T 7f849897f6dd4a80a036824247264ebc P 54c1a210534e44f593a626cf54191b02: Deleting log segment in path: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502530812-810-0/minicluster-data/ts-0-root/wals/7f849897f6dd4a80a036824247264ebc/wal-000000031 (ops 146-150)
I20260812 06:18:32.620245  1156 log.cc:1079] T 7f849897f6dd4a80a036824247264ebc P 54c1a210534e44f593a626cf54191b02: Deleting log segment in path: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502530812-810-0/minicluster-data/ts-0-root/wals/7f849897f6dd4a80a036824247264ebc/wal-000000032 (ops 151-154)
I20260812 06:18:32.620286  1156 log.cc:1079] T 7f849897f6dd4a80a036824247264ebc P 54c1a210534e44f593a626cf54191b02: Deleting log segment in path: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502530812-810-0/minicluster-data/ts-0-root/wals/7f849897f6dd4a80a036824247264ebc/wal-000000033 (ops 155-159)
I20260812 06:18:32.620326  1156 log.cc:1079] T 7f849897f6dd4a80a036824247264ebc P 54c1a210534e44f593a626cf54191b02: Deleting log segment in path: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502530812-810-0/minicluster-data/ts-0-root/wals/7f849897f6dd4a80a036824247264ebc/wal-000000034 (ops 160-164)
I20260812 06:18:32.620366  1156 log.cc:1079] T 7f849897f6dd4a80a036824247264ebc P 54c1a210534e44f593a626cf54191b02: Deleting log segment in path: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502530812-810-0/minicluster-data/ts-0-root/wals/7f849897f6dd4a80a036824247264ebc/wal-000000035 (ops 165-169)
I20260812 06:18:32.620406  1156 log.cc:1079] T 7f849897f6dd4a80a036824247264ebc P 54c1a210534e44f593a626cf54191b02: Deleting log segment in path: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502530812-810-0/minicluster-data/ts-0-root/wals/7f849897f6dd4a80a036824247264ebc/wal-000000036 (ops 170-174)
I20260812 06:18:32.620446  1156 log.cc:1079] T 7f849897f6dd4a80a036824247264ebc P 54c1a210534e44f593a626cf54191b02: Deleting log segment in path: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502530812-810-0/minicluster-data/ts-0-root/wals/7f849897f6dd4a80a036824247264ebc/wal-000000037 (ops 175-179)
I20260812 06:18:32.620486  1156 log.cc:1079] T 7f849897f6dd4a80a036824247264ebc P 54c1a210534e44f593a626cf54191b02: Deleting log segment in path: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502530812-810-0/minicluster-data/ts-0-root/wals/7f849897f6dd4a80a036824247264ebc/wal-000000038 (ops 180-184)
I20260812 06:18:32.620512  1156 log.cc:1079] T 7f849897f6dd4a80a036824247264ebc P 54c1a210534e44f593a626cf54191b02: Deleting log segment in path: /tmp/dist-test-taska3u3Pz/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515502530812-810-0/minicluster-data/ts-0-root/wals/7f849897f6dd4a80a036824247264ebc/wal-000000039 (ops 185-189)
I20260812 06:18:32.647181  1156 maintenance_manager.cc:643] P 54c1a210534e44f593a626cf54191b02: LogGCOp(7f849897f6dd4a80a036824247264ebc) complete. Timing: real 0.027s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:18:32.647650  1225 maintenance_manager.cc:419] P 54c1a210534e44f593a626cf54191b02: Scheduling UndoDeltaBlockGCOp(7f849897f6dd4a80a036824247264ebc): 462 bytes on disk
I20260812 06:18:32.648108  1156 maintenance_manager.cc:643] P 54c1a210534e44f593a626cf54191b02: UndoDeltaBlockGCOp(7f849897f6dd4a80a036824247264ebc) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4}
I20260812 06:18:32.648792  1225 maintenance_manager.cc:419] P 54c1a210534e44f593a626cf54191b02: Scheduling FlushDeltaMemStoresOp(7f849897f6dd4a80a036824247264ebc): perf score=3.181125
I20260812 06:18:32.663726  1156 maintenance_manager.cc:643] P 54c1a210534e44f593a626cf54191b02: FlushDeltaMemStoresOp(7f849897f6dd4a80a036824247264ebc) complete. Timing: real 0.015s	user 0.001s	sys 0.009s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4444,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:32.664140  1225 maintenance_manager.cc:419] P 54c1a210534e44f593a626cf54191b02: Scheduling FlushDeltaMemStoresOp(7f849897f6dd4a80a036824247264ebc): perf score=2.188937
I20260812 06:18:32.673552  1156 maintenance_manager.cc:643] P 54c1a210534e44f593a626cf54191b02: FlushDeltaMemStoresOp(7f849897f6dd4a80a036824247264ebc) complete. Timing: real 0.009s	user 0.000s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3591,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:32.674013  1225 maintenance_manager.cc:419] P 54c1a210534e44f593a626cf54191b02: Scheduling MajorDeltaCompactionOp(7f849897f6dd4a80a036824247264ebc): perf score=1.000000
I20260812 06:18:32.873487   810 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.897s	user 1.796s	sys 0.174s
I20260812 06:18:32.920425  1156 maintenance_manager.cc:643] P 54c1a210534e44f593a626cf54191b02: MajorDeltaCompactionOp(7f849897f6dd4a80a036824247264ebc) complete. Timing: real 0.246s	user 0.183s	sys 0.061s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020737,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"lbm_read_time_us":17835,"lbm_reads_lt_1ms":770,"lbm_write_time_us":42757,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":9472,"update_count":3500}
I20260812 06:18:32.920938  1225 maintenance_manager.cc:419] P 54c1a210534e44f593a626cf54191b02: Scheduling FlushDeltaMemStoresOp(7f849897f6dd4a80a036824247264ebc): perf score=14.095187
I20260812 06:18:32.957974  1156 maintenance_manager.cc:643] P 54c1a210534e44f593a626cf54191b02: FlushDeltaMemStoresOp(7f849897f6dd4a80a036824247264ebc) complete. Timing: real 0.037s	user 0.029s	sys 0.004s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":15837,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:32.958578  1225 maintenance_manager.cc:419] P 54c1a210534e44f593a626cf54191b02: Scheduling MajorDeltaCompactionOp(7f849897f6dd4a80a036824247264ebc): perf score=1.000000
I20260812 06:18:32.967002   810 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.093s	user 0.002s	sys 0.000s
I20260812 06:18:32.967509   810 tablet_server.cc:179] TabletServer@127.0.202.129:0 shutting down...
I20260812 06:18:33.077705  1156 maintenance_manager.cc:643] P 54c1a210534e44f593a626cf54191b02: MajorDeltaCompactionOp(7f849897f6dd4a80a036824247264ebc) complete. Timing: real 0.119s	user 0.077s	sys 0.041s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713152,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":364,"lbm_read_time_us":11318,"lbm_reads_lt_1ms":467,"lbm_write_time_us":20225,"lbm_writes_lt_1ms":443,"mutex_wait_us":22,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":22912,"update_count":2000}
I20260812 06:18:33.078394   810 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:33.078758   810 tablet_replica.cc:333] T 7f849897f6dd4a80a036824247264ebc P 54c1a210534e44f593a626cf54191b02: stopping tablet replica
I20260812 06:18:33.078922   810 raft_consensus.cc:2243] T 7f849897f6dd4a80a036824247264ebc P 54c1a210534e44f593a626cf54191b02 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:33.079100   810 raft_consensus.cc:2272] T 7f849897f6dd4a80a036824247264ebc P 54c1a210534e44f593a626cf54191b02 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:33.093564   810 tablet_server.cc:196] TabletServer@127.0.202.129:0 shutdown complete.
I20260812 06:18:33.116643   810 master.cc:562] Master@127.0.202.190:39303 shutting down...
I20260812 06:18:33.120039   810 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 1b1a88a7eaf246f0a1201c5f04bacef0 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:33.120246   810 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 1b1a88a7eaf246f0a1201c5f04bacef0 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:33.120333   810 tablet_replica.cc:333] T 00000000000000000000000000000000 P 1b1a88a7eaf246f0a1201c5f04bacef0: stopping tablet replica
I20260812 06:18:33.132709   810 master.cc:584] Master@127.0.202.190:39303 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5454 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10682 ms total)

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