[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:16:37.739604 29854 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.29.39.190:40587
I20260812 06:16:37.740680 29854 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:16:37.741389 29854 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:37.747701 29859 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:16:37.747720 29860 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:16:37.748070 29862 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:16:37.748083 29854 server_base.cc:1061] running on GCE node
I20260812 06:16:37.748548 29854 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:37.748662 29854 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:16:37.748742 29854 hybrid_clock.cc:648] HybridClock initialized: now 1786515397748740 us; error 0 us; skew 500 ppm
I20260812 06:16:37.750569 29854 webserver.cc:533] Webserver started at http://127.29.39.190:37231/ using document root <none> and password file <none>
I20260812 06:16:37.751121 29854 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:37.751178 29854 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:37.751469 29854 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:37.753242 29854 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397728536-29854-0/minicluster-data/master-0-root/instance:
uuid: "9b7d7b2750614138b8d2bababd531c38"
format_stamp: "Formatted at 2026-08-12 06:16:37 on dist-test-slave-cbsf"
I20260812 06:16:37.756999 29854 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.002s	sys 0.002s
I20260812 06:16:37.759217 29869 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:37.760191 29854 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:16:37.760339 29854 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397728536-29854-0/minicluster-data/master-0-root
uuid: "9b7d7b2750614138b8d2bababd531c38"
format_stamp: "Formatted at 2026-08-12 06:16:37 on dist-test-slave-cbsf"
I20260812 06:16:37.760449 29854 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397728536-29854-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397728536-29854-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397728536-29854-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:16:37.773895 29854 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:37.774648 29854 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:16:37.774863 29854 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:37.783696 29854 rpc_server.cc:307] RPC server started. Bound to: 127.29.39.190:40587
I20260812 06:16:37.783708 29932 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.29.39.190:40587 every 8 connection(s)
I20260812 06:16:37.786177 29933 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:16:37.791617 29933 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 9b7d7b2750614138b8d2bababd531c38: Bootstrap starting.
I20260812 06:16:37.794090 29933 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 9b7d7b2750614138b8d2bababd531c38: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:37.794984 29933 log.cc:826] T 00000000000000000000000000000000 P 9b7d7b2750614138b8d2bababd531c38: Log is configured to *not* fsync() on all Append() calls
I20260812 06:16:37.796772 29933 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 9b7d7b2750614138b8d2bababd531c38: No bootstrap required, opened a new log
I20260812 06:16:37.799664 29933 raft_consensus.cc:359] T 00000000000000000000000000000000 P 9b7d7b2750614138b8d2bababd531c38 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9b7d7b2750614138b8d2bababd531c38" member_type: VOTER }
I20260812 06:16:37.799850 29933 raft_consensus.cc:385] T 00000000000000000000000000000000 P 9b7d7b2750614138b8d2bababd531c38 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:37.799893 29933 raft_consensus.cc:740] T 00000000000000000000000000000000 P 9b7d7b2750614138b8d2bababd531c38 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 9b7d7b2750614138b8d2bababd531c38, State: Initialized, Role: FOLLOWER
I20260812 06:16:37.800439 29933 consensus_queue.cc:260] T 00000000000000000000000000000000 P 9b7d7b2750614138b8d2bababd531c38 [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: "9b7d7b2750614138b8d2bababd531c38" member_type: VOTER }
I20260812 06:16:37.800577 29933 raft_consensus.cc:399] T 00000000000000000000000000000000 P 9b7d7b2750614138b8d2bababd531c38 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:37.800621 29933 raft_consensus.cc:493] T 00000000000000000000000000000000 P 9b7d7b2750614138b8d2bababd531c38 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:37.800787 29933 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 9b7d7b2750614138b8d2bababd531c38 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:37.801607 29933 raft_consensus.cc:515] T 00000000000000000000000000000000 P 9b7d7b2750614138b8d2bababd531c38 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9b7d7b2750614138b8d2bababd531c38" member_type: VOTER }
I20260812 06:16:37.802028 29933 leader_election.cc:304] T 00000000000000000000000000000000 P 9b7d7b2750614138b8d2bababd531c38 [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: 9b7d7b2750614138b8d2bababd531c38; no voters: 
I20260812 06:16:37.802316 29933 leader_election.cc:290] T 00000000000000000000000000000000 P 9b7d7b2750614138b8d2bababd531c38 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:37.802556 29937 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 9b7d7b2750614138b8d2bababd531c38 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:37.802815 29937 raft_consensus.cc:697] T 00000000000000000000000000000000 P 9b7d7b2750614138b8d2bababd531c38 [term 1 LEADER]: Becoming Leader. State: Replica: 9b7d7b2750614138b8d2bababd531c38, State: Running, Role: LEADER
I20260812 06:16:37.803265 29937 consensus_queue.cc:237] T 00000000000000000000000000000000 P 9b7d7b2750614138b8d2bababd531c38 [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: "9b7d7b2750614138b8d2bababd531c38" member_type: VOTER }
I20260812 06:16:37.803478 29933 sys_catalog.cc:565] T 00000000000000000000000000000000 P 9b7d7b2750614138b8d2bababd531c38 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:16:37.805507 29938 sys_catalog.cc:455] T 00000000000000000000000000000000 P 9b7d7b2750614138b8d2bababd531c38 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "9b7d7b2750614138b8d2bababd531c38" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9b7d7b2750614138b8d2bababd531c38" member_type: VOTER } }
I20260812 06:16:37.805507 29939 sys_catalog.cc:455] T 00000000000000000000000000000000 P 9b7d7b2750614138b8d2bababd531c38 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 9b7d7b2750614138b8d2bababd531c38. Latest consensus state: current_term: 1 leader_uuid: "9b7d7b2750614138b8d2bababd531c38" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9b7d7b2750614138b8d2bababd531c38" member_type: VOTER } }
I20260812 06:16:37.805667 29938 sys_catalog.cc:458] T 00000000000000000000000000000000 P 9b7d7b2750614138b8d2bababd531c38 [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:37.805725 29939 sys_catalog.cc:458] T 00000000000000000000000000000000 P 9b7d7b2750614138b8d2bababd531c38 [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:37.805965 29854 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:16:37.806118 29952 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:16:37.808477 29952 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:16:37.813544 29952 catalog_manager.cc:1383] Generated new cluster ID: 1b28923a70da44b8be5f026a1dccf4ad
I20260812 06:16:37.813629 29952 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:16:37.823863 29952 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:16:37.824940 29952 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:16:37.830883 29952 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 9b7d7b2750614138b8d2bababd531c38: Generated new TSK 0
I20260812 06:16:37.831578 29952 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:16:37.838763 29854 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:37.841957 29958 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:16:37.842057 29957 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:16:37.842011 29960 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:16:37.842708 29854 server_base.cc:1061] running on GCE node
I20260812 06:16:37.842918 29854 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:37.842967 29854 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:16:37.842990 29854 hybrid_clock.cc:648] HybridClock initialized: now 1786515397842990 us; error 0 us; skew 500 ppm
I20260812 06:16:37.844003 29854 webserver.cc:533] Webserver started at http://127.29.39.129:42517/ using document root <none> and password file <none>
I20260812 06:16:37.844187 29854 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:37.844244 29854 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:37.844317 29854 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:37.844818 29854 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397728536-29854-0/minicluster-data/ts-0-root/instance:
uuid: "21ad0cf441984a159db4c33dfcd673c1"
format_stamp: "Formatted at 2026-08-12 06:16:37 on dist-test-slave-cbsf"
I20260812 06:16:37.846719 29854 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.001s	sys 0.001s
I20260812 06:16:37.847994 29965 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:37.848332 29854 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:16:37.848433 29854 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397728536-29854-0/minicluster-data/ts-0-root
uuid: "21ad0cf441984a159db4c33dfcd673c1"
format_stamp: "Formatted at 2026-08-12 06:16:37 on dist-test-slave-cbsf"
I20260812 06:16:37.848556 29854 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397728536-29854-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397728536-29854-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397728536-29854-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:16:37.857808 29854 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:37.858395 29854 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:37.858937 29854 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:16:37.859892 29854 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:16:37.859977 29854 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:37.860121 29854 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:16:37.860157 29854 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:37.867617 29854 rpc_server.cc:307] RPC server started. Bound to: 127.29.39.129:37793
I20260812 06:16:37.867679 30045 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.29.39.129:37793 every 8 connection(s)
I20260812 06:16:37.878276 30046 heartbeater.cc:344] Connected to a master server at 127.29.39.190:40587
I20260812 06:16:37.878583 30046 heartbeater.cc:461] Registering TS with master...
I20260812 06:16:37.879161 30046 heartbeater.cc:507] Master 127.29.39.190:40587 requested a full tablet report, sending...
I20260812 06:16:37.880816 29891 ts_manager.cc:194] Registered new tserver with Master: 21ad0cf441984a159db4c33dfcd673c1 (127.29.39.129:37793)
I20260812 06:16:37.881660 29854 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.013350132s
I20260812 06:16:37.882401 29891 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:59994
I20260812 06:16:37.892364 29891 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:59998:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:16:37.908499 30000 tablet_service.cc:1511] Processing CreateTablet for tablet 48161396392a40c095b54647ea5dec57 (DEFAULT_TABLE table=heavy-update-compaction-test [id=df6a8667cea44013b733dd201af1510b]), partition=
I20260812 06:16:37.909057 30000 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 48161396392a40c095b54647ea5dec57. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:16:37.911939 30059 tablet_bootstrap.cc:492] T 48161396392a40c095b54647ea5dec57 P 21ad0cf441984a159db4c33dfcd673c1: Bootstrap starting.
I20260812 06:16:37.912899 30059 tablet_bootstrap.cc:654] T 48161396392a40c095b54647ea5dec57 P 21ad0cf441984a159db4c33dfcd673c1: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:37.914039 30059 tablet_bootstrap.cc:492] T 48161396392a40c095b54647ea5dec57 P 21ad0cf441984a159db4c33dfcd673c1: No bootstrap required, opened a new log
I20260812 06:16:37.914186 30059 ts_tablet_manager.cc:1403] T 48161396392a40c095b54647ea5dec57 P 21ad0cf441984a159db4c33dfcd673c1: Time spent bootstrapping tablet: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:16:37.914620 30059 raft_consensus.cc:359] T 48161396392a40c095b54647ea5dec57 P 21ad0cf441984a159db4c33dfcd673c1 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "21ad0cf441984a159db4c33dfcd673c1" member_type: VOTER last_known_addr { host: "127.29.39.129" port: 37793 } }
I20260812 06:16:37.914742 30059 raft_consensus.cc:385] T 48161396392a40c095b54647ea5dec57 P 21ad0cf441984a159db4c33dfcd673c1 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:37.914811 30059 raft_consensus.cc:740] T 48161396392a40c095b54647ea5dec57 P 21ad0cf441984a159db4c33dfcd673c1 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 21ad0cf441984a159db4c33dfcd673c1, State: Initialized, Role: FOLLOWER
I20260812 06:16:37.914979 30059 consensus_queue.cc:260] T 48161396392a40c095b54647ea5dec57 P 21ad0cf441984a159db4c33dfcd673c1 [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: "21ad0cf441984a159db4c33dfcd673c1" member_type: VOTER last_known_addr { host: "127.29.39.129" port: 37793 } }
I20260812 06:16:37.915125 30059 raft_consensus.cc:399] T 48161396392a40c095b54647ea5dec57 P 21ad0cf441984a159db4c33dfcd673c1 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:37.915184 30059 raft_consensus.cc:493] T 48161396392a40c095b54647ea5dec57 P 21ad0cf441984a159db4c33dfcd673c1 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:37.915433 30059 raft_consensus.cc:3060] T 48161396392a40c095b54647ea5dec57 P 21ad0cf441984a159db4c33dfcd673c1 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:37.916251 30059 raft_consensus.cc:515] T 48161396392a40c095b54647ea5dec57 P 21ad0cf441984a159db4c33dfcd673c1 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "21ad0cf441984a159db4c33dfcd673c1" member_type: VOTER last_known_addr { host: "127.29.39.129" port: 37793 } }
I20260812 06:16:37.916409 30059 leader_election.cc:304] T 48161396392a40c095b54647ea5dec57 P 21ad0cf441984a159db4c33dfcd673c1 [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: 21ad0cf441984a159db4c33dfcd673c1; no voters: 
I20260812 06:16:37.916643 30059 leader_election.cc:290] T 48161396392a40c095b54647ea5dec57 P 21ad0cf441984a159db4c33dfcd673c1 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:37.916755 30062 raft_consensus.cc:2804] T 48161396392a40c095b54647ea5dec57 P 21ad0cf441984a159db4c33dfcd673c1 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:37.916944 30062 raft_consensus.cc:697] T 48161396392a40c095b54647ea5dec57 P 21ad0cf441984a159db4c33dfcd673c1 [term 1 LEADER]: Becoming Leader. State: Replica: 21ad0cf441984a159db4c33dfcd673c1, State: Running, Role: LEADER
I20260812 06:16:37.917045 30059 ts_tablet_manager.cc:1434] T 48161396392a40c095b54647ea5dec57 P 21ad0cf441984a159db4c33dfcd673c1: Time spent starting tablet: real 0.003s	user 0.000s	sys 0.003s
I20260812 06:16:37.917169 30062 consensus_queue.cc:237] T 48161396392a40c095b54647ea5dec57 P 21ad0cf441984a159db4c33dfcd673c1 [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: "21ad0cf441984a159db4c33dfcd673c1" member_type: VOTER last_known_addr { host: "127.29.39.129" port: 37793 } }
I20260812 06:16:37.917402 30046 heartbeater.cc:499] Master 127.29.39.190:40587 was elected leader, sending a full tablet report...
I20260812 06:16:37.920171 29891 catalog_manager.cc:5719] T 48161396392a40c095b54647ea5dec57 P 21ad0cf441984a159db4c33dfcd673c1 reported cstate change: term changed from 0 to 1, leader changed from <none> to 21ad0cf441984a159db4c33dfcd673c1 (127.29.39.129). New cstate: current_term: 1 leader_uuid: "21ad0cf441984a159db4c33dfcd673c1" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "21ad0cf441984a159db4c33dfcd673c1" member_type: VOTER last_known_addr { host: "127.29.39.129" port: 37793 } health_report { overall_health: HEALTHY } } }
I20260812 06:16:37.987931 29854 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.059s	user 0.015s	sys 0.011s
I20260812 06:16:38.118932 30047 maintenance_manager.cc:419] P 21ad0cf441984a159db4c33dfcd673c1: Scheduling FlushMRSOp(48161396392a40c095b54647ea5dec57): perf score=15.086190
I20260812 06:16:38.311110 29971 maintenance_manager.cc:643] P 21ad0cf441984a159db4c33dfcd673c1: FlushMRSOp(48161396392a40c095b54647ea5dec57) complete. Timing: real 0.192s	user 0.162s	sys 0.020s Metrics: {"bytes_written":14522789,"cfile_init":1,"compiler_manager_pool.queue_time_us":191,"delete_count":0,"dirs.queue_time_us":84,"dirs.run_cpu_time_us":263,"dirs.run_wall_time_us":1249,"drs_written":1,"lbm_read_time_us":87,"lbm_reads_lt_1ms":4,"lbm_write_time_us":46388,"lbm_writes_lt_1ms":721,"mutex_wait_us":2393,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":169216,"thread_start_us":121,"threads_started":1,"update_count":1770}
I20260812 06:16:38.312407 30047 maintenance_manager.cc:419] P 21ad0cf441984a159db4c33dfcd673c1: Scheduling LogGCOp(48161396392a40c095b54647ea5dec57): free 20743880 bytes of WAL
I20260812 06:16:38.312803 29971 log_reader.cc:385] T 48161396392a40c095b54647ea5dec57: removed 2 log segments from log reader
I20260812 06:16:38.312876 29971 log.cc:1079] T 48161396392a40c095b54647ea5dec57 P 21ad0cf441984a159db4c33dfcd673c1: Deleting log segment in path: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397728536-29854-0/minicluster-data/ts-0-root/wals/48161396392a40c095b54647ea5dec57/wal-000000001 (ops 1-6)
I20260812 06:16:38.312986 29971 log.cc:1079] T 48161396392a40c095b54647ea5dec57 P 21ad0cf441984a159db4c33dfcd673c1: Deleting log segment in path: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397728536-29854-0/minicluster-data/ts-0-root/wals/48161396392a40c095b54647ea5dec57/wal-000000002 (ops 7-11)
I20260812 06:16:38.318451 29971 maintenance_manager.cc:643] P 21ad0cf441984a159db4c33dfcd673c1: LogGCOp(48161396392a40c095b54647ea5dec57) complete. Timing: real 0.006s	user 0.001s	sys 0.004s Metrics: {}
I20260812 06:16:38.318859 30047 maintenance_manager.cc:419] P 21ad0cf441984a159db4c33dfcd673c1: Scheduling FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57): perf score=4.173312
I20260812 06:16:38.365579 29971 maintenance_manager.cc:643] P 21ad0cf441984a159db4c33dfcd673c1: FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57) complete. Timing: real 0.047s	user 0.017s	sys 0.012s Metrics: {"bytes_written":5579537,"delete_count":0,"lbm_write_time_us":9527,"lbm_writes_lt_1ms":139,"reinsert_count":0,"update_count":680}
I20260812 06:16:38.366305 30047 maintenance_manager.cc:419] P 21ad0cf441984a159db4c33dfcd673c1: Scheduling UndoDeltaBlockGCOp(48161396392a40c095b54647ea5dec57): 12719216 bytes on disk
I20260812 06:16:38.367026 29971 maintenance_manager.cc:643] P 21ad0cf441984a159db4c33dfcd673c1: UndoDeltaBlockGCOp(48161396392a40c095b54647ea5dec57) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":84,"lbm_reads_lt_1ms":4}
I20260812 06:16:38.367476 30047 maintenance_manager.cc:419] P 21ad0cf441984a159db4c33dfcd673c1: Scheduling FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57): perf score=2.188937
I20260812 06:16:38.383910 29971 maintenance_manager.cc:643] P 21ad0cf441984a159db4c33dfcd673c1: FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57) complete. Timing: real 0.016s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6585,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:38.384577 30047 maintenance_manager.cc:419] P 21ad0cf441984a159db4c33dfcd673c1: Scheduling MajorDeltaCompactionOp(48161396392a40c095b54647ea5dec57): perf score=1.000000
I20260812 06:16:38.577850 29971 maintenance_manager.cc:643] P 21ad0cf441984a159db4c33dfcd673c1: MajorDeltaCompactionOp(48161396392a40c095b54647ea5dec57) complete. Timing: real 0.193s	user 0.128s	sys 0.064s Metrics: {"cfile_cache_miss":623,"cfile_cache_miss_bytes":28466979,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":641,"lbm_read_time_us":12502,"lbm_reads_lt_1ms":659,"lbm_write_time_us":35553,"lbm_writes_lt_1ms":633,"peak_mem_usage":74091738,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":340,"threads_started":5,"update_count":2950}
I20260812 06:16:38.578378 30047 maintenance_manager.cc:419] P 21ad0cf441984a159db4c33dfcd673c1: Scheduling FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57): perf score=11.118625
I20260812 06:16:38.617146 29971 maintenance_manager.cc:643] P 21ad0cf441984a159db4c33dfcd673c1: FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57) complete. Timing: real 0.039s	user 0.012s	sys 0.026s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":16745,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:16:38.617796 30047 maintenance_manager.cc:419] P 21ad0cf441984a159db4c33dfcd673c1: Scheduling FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57): perf score=2.188937
I20260812 06:16:38.652853 29971 maintenance_manager.cc:643] P 21ad0cf441984a159db4c33dfcd673c1: FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57) complete. Timing: real 0.035s	user 0.014s	sys 0.006s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6851,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":92,"reinsert_count":0,"update_count":450}
I20260812 06:16:38.653419 30047 maintenance_manager.cc:419] P 21ad0cf441984a159db4c33dfcd673c1: Scheduling FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57): perf score=2.188937
I20260812 06:16:38.664358 29971 maintenance_manager.cc:643] P 21ad0cf441984a159db4c33dfcd673c1: FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4285,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:38.665061 30047 maintenance_manager.cc:419] P 21ad0cf441984a159db4c33dfcd673c1: Scheduling MajorDeltaCompactionOp(48161396392a40c095b54647ea5dec57): perf score=1.000000
I20260812 06:16:38.832396 29971 maintenance_manager.cc:643] P 21ad0cf441984a159db4c33dfcd673c1: MajorDeltaCompactionOp(48161396392a40c095b54647ea5dec57) complete. Timing: real 0.167s	user 0.118s	sys 0.048s 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":236,"lbm_read_time_us":11672,"lbm_reads_lt_1ms":573,"lbm_write_time_us":32817,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":542,"mutex_wait_us":24,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":16896,"update_count":2500}
I20260812 06:16:38.835654 30047 maintenance_manager.cc:419] P 21ad0cf441984a159db4c33dfcd673c1: Scheduling FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57): perf score=10.126437
I20260812 06:16:38.865860 29971 maintenance_manager.cc:643] P 21ad0cf441984a159db4c33dfcd673c1: FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57) complete. Timing: real 0.030s	user 0.015s	sys 0.014s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":12974,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:38.866475 30047 maintenance_manager.cc:419] P 21ad0cf441984a159db4c33dfcd673c1: Scheduling FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57): perf score=2.188937
I20260812 06:16:38.880919 29971 maintenance_manager.cc:643] P 21ad0cf441984a159db4c33dfcd673c1: FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57) complete. Timing: real 0.014s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5628,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:38.881367 30047 maintenance_manager.cc:419] P 21ad0cf441984a159db4c33dfcd673c1: Scheduling MajorDeltaCompactionOp(48161396392a40c095b54647ea5dec57): perf score=1.000000
I20260812 06:16:39.038005 29971 maintenance_manager.cc:643] P 21ad0cf441984a159db4c33dfcd673c1: MajorDeltaCompactionOp(48161396392a40c095b54647ea5dec57) complete. Timing: real 0.156s	user 0.095s	sys 0.055s 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":796,"lbm_read_time_us":8783,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26925,"lbm_writes_lt_1ms":443,"mutex_wait_us":271,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11264,"update_count":2000}
I20260812 06:16:39.038728 30047 maintenance_manager.cc:419] P 21ad0cf441984a159db4c33dfcd673c1: Scheduling FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57): perf score=10.126437
I20260812 06:16:39.082608 29971 maintenance_manager.cc:643] P 21ad0cf441984a159db4c33dfcd673c1: FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57) complete. Timing: real 0.044s	user 0.019s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14709,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:39.083139 30047 maintenance_manager.cc:419] P 21ad0cf441984a159db4c33dfcd673c1: Scheduling FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57): perf score=2.188937
I20260812 06:16:39.094182 29971 maintenance_manager.cc:643] P 21ad0cf441984a159db4c33dfcd673c1: FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57) complete. Timing: real 0.011s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3972,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:39.094864 30047 maintenance_manager.cc:419] P 21ad0cf441984a159db4c33dfcd673c1: Scheduling MajorDeltaCompactionOp(48161396392a40c095b54647ea5dec57): perf score=1.000000
I20260812 06:16:39.220916 29971 maintenance_manager.cc:643] P 21ad0cf441984a159db4c33dfcd673c1: MajorDeltaCompactionOp(48161396392a40c095b54647ea5dec57) complete. Timing: real 0.126s	user 0.093s	sys 0.032s 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":699,"lbm_read_time_us":7290,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25788,"lbm_writes_lt_1ms":443,"mutex_wait_us":302,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":658816,"update_count":2000}
I20260812 06:16:39.221580 30047 maintenance_manager.cc:419] P 21ad0cf441984a159db4c33dfcd673c1: Scheduling FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57): perf score=10.126437
I20260812 06:16:39.273064 29971 maintenance_manager.cc:643] P 21ad0cf441984a159db4c33dfcd673c1: FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57) complete. Timing: real 0.051s	user 0.025s	sys 0.017s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":18648,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:39.273592 30047 maintenance_manager.cc:419] P 21ad0cf441984a159db4c33dfcd673c1: Scheduling FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57): perf score=2.188937
I20260812 06:16:39.285102 29971 maintenance_manager.cc:643] P 21ad0cf441984a159db4c33dfcd673c1: FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4144,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:39.285611 30047 maintenance_manager.cc:419] P 21ad0cf441984a159db4c33dfcd673c1: Scheduling MajorDeltaCompactionOp(48161396392a40c095b54647ea5dec57): perf score=1.000000
I20260812 06:16:39.404546 29971 maintenance_manager.cc:643] P 21ad0cf441984a159db4c33dfcd673c1: MajorDeltaCompactionOp(48161396392a40c095b54647ea5dec57) complete. Timing: real 0.119s	user 0.102s	sys 0.016s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":187,"lbm_read_time_us":8828,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21205,"lbm_writes_lt_1ms":443,"mutex_wait_us":45,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8064,"update_count":2000}
I20260812 06:16:39.405194 30047 maintenance_manager.cc:419] P 21ad0cf441984a159db4c33dfcd673c1: Scheduling FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57): perf score=10.126437
I20260812 06:16:39.453918 29971 maintenance_manager.cc:643] P 21ad0cf441984a159db4c33dfcd673c1: FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57) complete. Timing: real 0.049s	user 0.022s	sys 0.024s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16405,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:16:39.454507 30047 maintenance_manager.cc:419] P 21ad0cf441984a159db4c33dfcd673c1: Scheduling FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57): perf score=2.188937
I20260812 06:16:39.465706 29971 maintenance_manager.cc:643] P 21ad0cf441984a159db4c33dfcd673c1: FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57) complete. Timing: real 0.011s	user 0.000s	sys 0.010s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4292,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:39.466245 30047 maintenance_manager.cc:419] P 21ad0cf441984a159db4c33dfcd673c1: Scheduling MajorDeltaCompactionOp(48161396392a40c095b54647ea5dec57): perf score=1.000000
I20260812 06:16:39.613240 29971 maintenance_manager.cc:643] P 21ad0cf441984a159db4c33dfcd673c1: MajorDeltaCompactionOp(48161396392a40c095b54647ea5dec57) complete. Timing: real 0.147s	user 0.109s	sys 0.038s 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":1090,"lbm_read_time_us":10835,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23330,"lbm_writes_lt_1ms":443,"mutex_wait_us":358,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:16:39.613988 30047 maintenance_manager.cc:419] P 21ad0cf441984a159db4c33dfcd673c1: Scheduling FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57): perf score=10.126437
I20260812 06:16:39.657630 29971 maintenance_manager.cc:643] P 21ad0cf441984a159db4c33dfcd673c1: FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57) complete. Timing: real 0.043s	user 0.026s	sys 0.013s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17294,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:39.658182 30047 maintenance_manager.cc:419] P 21ad0cf441984a159db4c33dfcd673c1: Scheduling FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57): perf score=2.188937
I20260812 06:16:39.669824 29971 maintenance_manager.cc:643] P 21ad0cf441984a159db4c33dfcd673c1: FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57) complete. Timing: real 0.011s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4246,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:39.670516 30047 maintenance_manager.cc:419] P 21ad0cf441984a159db4c33dfcd673c1: Scheduling FlushMRSOp(48161396392a40c095b54647ea5dec57): perf score=1.000000
I20260812 06:16:39.705506 29971 maintenance_manager.cc:643] P 21ad0cf441984a159db4c33dfcd673c1: FlushMRSOp(48161396392a40c095b54647ea5dec57) complete. Timing: real 0.035s	user 0.029s	sys 0.005s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":77,"dirs.run_cpu_time_us":227,"dirs.run_wall_time_us":1536,"drs_written":1,"lbm_read_time_us":91,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1702,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:16:39.706367 30047 maintenance_manager.cc:419] P 21ad0cf441984a159db4c33dfcd673c1: Scheduling LogGCOp(48161396392a40c095b54647ea5dec57): free 120553391 bytes of WAL
I20260812 06:16:39.706614 29971 log_reader.cc:385] T 48161396392a40c095b54647ea5dec57: removed 12 log segments from log reader
I20260812 06:16:39.706673 29971 log.cc:1079] T 48161396392a40c095b54647ea5dec57 P 21ad0cf441984a159db4c33dfcd673c1: Deleting log segment in path: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397728536-29854-0/minicluster-data/ts-0-root/wals/48161396392a40c095b54647ea5dec57/wal-000000003 (ops 12-16)
I20260812 06:16:39.706724 29971 log.cc:1079] T 48161396392a40c095b54647ea5dec57 P 21ad0cf441984a159db4c33dfcd673c1: Deleting log segment in path: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397728536-29854-0/minicluster-data/ts-0-root/wals/48161396392a40c095b54647ea5dec57/wal-000000004 (ops 17-21)
I20260812 06:16:39.706781 29971 log.cc:1079] T 48161396392a40c095b54647ea5dec57 P 21ad0cf441984a159db4c33dfcd673c1: Deleting log segment in path: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397728536-29854-0/minicluster-data/ts-0-root/wals/48161396392a40c095b54647ea5dec57/wal-000000005 (ops 22-26)
I20260812 06:16:39.706825 29971 log.cc:1079] T 48161396392a40c095b54647ea5dec57 P 21ad0cf441984a159db4c33dfcd673c1: Deleting log segment in path: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397728536-29854-0/minicluster-data/ts-0-root/wals/48161396392a40c095b54647ea5dec57/wal-000000006 (ops 27-30)
I20260812 06:16:39.706858 29971 log.cc:1079] T 48161396392a40c095b54647ea5dec57 P 21ad0cf441984a159db4c33dfcd673c1: Deleting log segment in path: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397728536-29854-0/minicluster-data/ts-0-root/wals/48161396392a40c095b54647ea5dec57/wal-000000007 (ops 31-35)
I20260812 06:16:39.706892 29971 log.cc:1079] T 48161396392a40c095b54647ea5dec57 P 21ad0cf441984a159db4c33dfcd673c1: Deleting log segment in path: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397728536-29854-0/minicluster-data/ts-0-root/wals/48161396392a40c095b54647ea5dec57/wal-000000008 (ops 36-40)
I20260812 06:16:39.706933 29971 log.cc:1079] T 48161396392a40c095b54647ea5dec57 P 21ad0cf441984a159db4c33dfcd673c1: Deleting log segment in path: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397728536-29854-0/minicluster-data/ts-0-root/wals/48161396392a40c095b54647ea5dec57/wal-000000009 (ops 41-45)
I20260812 06:16:39.706969 29971 log.cc:1079] T 48161396392a40c095b54647ea5dec57 P 21ad0cf441984a159db4c33dfcd673c1: Deleting log segment in path: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397728536-29854-0/minicluster-data/ts-0-root/wals/48161396392a40c095b54647ea5dec57/wal-000000010 (ops 46-50)
I20260812 06:16:39.707005 29971 log.cc:1079] T 48161396392a40c095b54647ea5dec57 P 21ad0cf441984a159db4c33dfcd673c1: Deleting log segment in path: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397728536-29854-0/minicluster-data/ts-0-root/wals/48161396392a40c095b54647ea5dec57/wal-000000011 (ops 51-54)
I20260812 06:16:39.707043 29971 log.cc:1079] T 48161396392a40c095b54647ea5dec57 P 21ad0cf441984a159db4c33dfcd673c1: Deleting log segment in path: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397728536-29854-0/minicluster-data/ts-0-root/wals/48161396392a40c095b54647ea5dec57/wal-000000012 (ops 55-59)
I20260812 06:16:39.707079 29971 log.cc:1079] T 48161396392a40c095b54647ea5dec57 P 21ad0cf441984a159db4c33dfcd673c1: Deleting log segment in path: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397728536-29854-0/minicluster-data/ts-0-root/wals/48161396392a40c095b54647ea5dec57/wal-000000013 (ops 60-64)
I20260812 06:16:39.707114 29971 log.cc:1079] T 48161396392a40c095b54647ea5dec57 P 21ad0cf441984a159db4c33dfcd673c1: Deleting log segment in path: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397728536-29854-0/minicluster-data/ts-0-root/wals/48161396392a40c095b54647ea5dec57/wal-000000014 (ops 65-69)
I20260812 06:16:39.731158 29971 maintenance_manager.cc:643] P 21ad0cf441984a159db4c33dfcd673c1: LogGCOp(48161396392a40c095b54647ea5dec57) complete. Timing: real 0.025s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:16:39.731573 30047 maintenance_manager.cc:419] P 21ad0cf441984a159db4c33dfcd673c1: Scheduling UndoDeltaBlockGCOp(48161396392a40c095b54647ea5dec57): 472 bytes on disk
I20260812 06:16:39.732115 29971 maintenance_manager.cc:643] P 21ad0cf441984a159db4c33dfcd673c1: UndoDeltaBlockGCOp(48161396392a40c095b54647ea5dec57) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4}
I20260812 06:16:39.732782 30047 maintenance_manager.cc:419] P 21ad0cf441984a159db4c33dfcd673c1: Scheduling FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57): perf score=4.173312
I20260812 06:16:39.758476 29971 maintenance_manager.cc:643] P 21ad0cf441984a159db4c33dfcd673c1: FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57) complete. Timing: real 0.025s	user 0.012s	sys 0.012s Metrics: {"bytes_written":5743633,"delete_count":0,"lbm_write_time_us":7634,"lbm_writes_lt_1ms":143,"reinsert_count":0,"update_count":700}
I20260812 06:16:39.759083 30047 maintenance_manager.cc:419] P 21ad0cf441984a159db4c33dfcd673c1: Scheduling FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57): perf score=1.196750
I20260812 06:16:39.766607 29971 maintenance_manager.cc:643] P 21ad0cf441984a159db4c33dfcd673c1: FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57) complete. Timing: real 0.007s	user 0.006s	sys 0.000s Metrics: {"bytes_written":2461654,"delete_count":0,"lbm_write_time_us":2455,"lbm_writes_lt_1ms":63,"reinsert_count":0,"update_count":300}
I20260812 06:16:39.767107 30047 maintenance_manager.cc:419] P 21ad0cf441984a159db4c33dfcd673c1: Scheduling MajorDeltaCompactionOp(48161396392a40c095b54647ea5dec57): perf score=1.000000
I20260812 06:16:39.984925 29971 maintenance_manager.cc:643] P 21ad0cf441984a159db4c33dfcd673c1: MajorDeltaCompactionOp(48161396392a40c095b54647ea5dec57) complete. Timing: real 0.218s	user 0.136s	sys 0.071s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877302,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":956,"lbm_read_time_us":15169,"lbm_reads_lt_1ms":674,"lbm_write_time_us":36751,"lbm_writes_lt_1ms":643,"mutex_wait_us":76,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":10880,"thread_start_us":80,"threads_started":1,"update_count":3000}
I20260812 06:16:39.985885 30047 maintenance_manager.cc:419] P 21ad0cf441984a159db4c33dfcd673c1: Scheduling FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57): perf score=14.095187
I20260812 06:16:40.048810 29971 maintenance_manager.cc:643] P 21ad0cf441984a159db4c33dfcd673c1: FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57) complete. Timing: real 0.063s	user 0.034s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21417,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:40.049794 30047 maintenance_manager.cc:419] P 21ad0cf441984a159db4c33dfcd673c1: Scheduling FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57): perf score=2.188937
I20260812 06:16:40.073307 29971 maintenance_manager.cc:643] P 21ad0cf441984a159db4c33dfcd673c1: FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57) complete. Timing: real 0.023s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5988,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":102,"reinsert_count":0,"update_count":500}
I20260812 06:16:40.075918 30047 maintenance_manager.cc:419] P 21ad0cf441984a159db4c33dfcd673c1: Scheduling MajorDeltaCompactionOp(48161396392a40c095b54647ea5dec57): perf score=1.000000
I20260812 06:16:40.264819 29971 maintenance_manager.cc:643] P 21ad0cf441984a159db4c33dfcd673c1: MajorDeltaCompactionOp(48161396392a40c095b54647ea5dec57) complete. Timing: real 0.189s	user 0.146s	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":488,"lbm_read_time_us":13729,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29810,"lbm_writes_lt_1ms":543,"mutex_wait_us":93,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5376,"update_count":2500}
I20260812 06:16:40.265551 30047 maintenance_manager.cc:419] P 21ad0cf441984a159db4c33dfcd673c1: Scheduling FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57): perf score=14.095187
I20260812 06:16:40.319298 29971 maintenance_manager.cc:643] P 21ad0cf441984a159db4c33dfcd673c1: FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57) complete. Timing: real 0.054s	user 0.028s	sys 0.021s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":22191,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:40.319856 30047 maintenance_manager.cc:419] P 21ad0cf441984a159db4c33dfcd673c1: Scheduling FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57): perf score=2.188937
I20260812 06:16:40.339036 29971 maintenance_manager.cc:643] P 21ad0cf441984a159db4c33dfcd673c1: FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57) complete. Timing: real 0.019s	user 0.006s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4257,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:40.339727 30047 maintenance_manager.cc:419] P 21ad0cf441984a159db4c33dfcd673c1: Scheduling MajorDeltaCompactionOp(48161396392a40c095b54647ea5dec57): perf score=1.000000
I20260812 06:16:40.537637 29971 maintenance_manager.cc:643] P 21ad0cf441984a159db4c33dfcd673c1: MajorDeltaCompactionOp(48161396392a40c095b54647ea5dec57) complete. Timing: real 0.198s	user 0.137s	sys 0.047s 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":586,"lbm_read_time_us":14213,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32636,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4736,"update_count":2500}
I20260812 06:16:40.541291 30047 maintenance_manager.cc:419] P 21ad0cf441984a159db4c33dfcd673c1: Scheduling FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57): perf score=14.095187
I20260812 06:16:40.590873 29971 maintenance_manager.cc:643] P 21ad0cf441984a159db4c33dfcd673c1: FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57) complete. Timing: real 0.049s	user 0.015s	sys 0.032s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":22116,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:40.591358 30047 maintenance_manager.cc:419] P 21ad0cf441984a159db4c33dfcd673c1: Scheduling FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57): perf score=2.188937
I20260812 06:16:40.602825 29971 maintenance_manager.cc:643] P 21ad0cf441984a159db4c33dfcd673c1: FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57) complete. Timing: real 0.011s	user 0.001s	sys 0.008s 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:16:40.603329 30047 maintenance_manager.cc:419] P 21ad0cf441984a159db4c33dfcd673c1: Scheduling MajorDeltaCompactionOp(48161396392a40c095b54647ea5dec57): perf score=1.000000
I20260812 06:16:40.800179 29971 maintenance_manager.cc:643] P 21ad0cf441984a159db4c33dfcd673c1: MajorDeltaCompactionOp(48161396392a40c095b54647ea5dec57) complete. Timing: real 0.197s	user 0.137s	sys 0.043s 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":643,"lbm_read_time_us":11483,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30785,"lbm_writes_lt_1ms":543,"mutex_wait_us":280,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14208,"update_count":2500}
I20260812 06:16:40.800899 30047 maintenance_manager.cc:419] P 21ad0cf441984a159db4c33dfcd673c1: Scheduling FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57): perf score=14.095187
I20260812 06:16:40.856971 29971 maintenance_manager.cc:643] P 21ad0cf441984a159db4c33dfcd673c1: FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57) complete. Timing: real 0.056s	user 0.032s	sys 0.023s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":25521,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:16:40.857599 30047 maintenance_manager.cc:419] P 21ad0cf441984a159db4c33dfcd673c1: Scheduling FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57): perf score=2.188937
I20260812 06:16:40.870272 29971 maintenance_manager.cc:643] P 21ad0cf441984a159db4c33dfcd673c1: FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57) complete. Timing: real 0.012s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4564,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:40.870831 30047 maintenance_manager.cc:419] P 21ad0cf441984a159db4c33dfcd673c1: Scheduling MajorDeltaCompactionOp(48161396392a40c095b54647ea5dec57): perf score=1.000000
I20260812 06:16:41.038060 29971 maintenance_manager.cc:643] P 21ad0cf441984a159db4c33dfcd673c1: MajorDeltaCompactionOp(48161396392a40c095b54647ea5dec57) complete. Timing: real 0.167s	user 0.124s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":555,"lbm_read_time_us":10324,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33007,"lbm_writes_lt_1ms":543,"mutex_wait_us":125,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13568,"update_count":2500}
I20260812 06:16:41.038679 30047 maintenance_manager.cc:419] P 21ad0cf441984a159db4c33dfcd673c1: Scheduling FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57): perf score=11.118625
I20260812 06:16:41.083353 29971 maintenance_manager.cc:643] P 21ad0cf441984a159db4c33dfcd673c1: FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57) complete. Timing: real 0.044s	user 0.023s	sys 0.019s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":17759,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:16:41.084111 30047 maintenance_manager.cc:419] P 21ad0cf441984a159db4c33dfcd673c1: Scheduling FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57): perf score=2.188937
I20260812 06:16:41.102581 29971 maintenance_manager.cc:643] P 21ad0cf441984a159db4c33dfcd673c1: FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57) complete. Timing: real 0.018s	user 0.004s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5104,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:41.103122 30047 maintenance_manager.cc:419] P 21ad0cf441984a159db4c33dfcd673c1: Scheduling FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57): perf score=2.188937
I20260812 06:16:41.114393 29971 maintenance_manager.cc:643] P 21ad0cf441984a159db4c33dfcd673c1: FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4054,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:41.115100 30047 maintenance_manager.cc:419] P 21ad0cf441984a159db4c33dfcd673c1: Scheduling MajorDeltaCompactionOp(48161396392a40c095b54647ea5dec57): perf score=1.000000
I20260812 06:16:41.285570 29971 maintenance_manager.cc:643] P 21ad0cf441984a159db4c33dfcd673c1: MajorDeltaCompactionOp(48161396392a40c095b54647ea5dec57) complete. Timing: real 0.170s	user 0.126s	sys 0.032s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774797,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1021,"lbm_read_time_us":10013,"lbm_reads_lt_1ms":573,"lbm_write_time_us":34063,"lbm_writes_lt_1ms":543,"mutex_wait_us":334,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13312,"update_count":2500}
I20260812 06:16:41.286226 30047 maintenance_manager.cc:419] P 21ad0cf441984a159db4c33dfcd673c1: Scheduling FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57): perf score=14.095187
I20260812 06:16:41.338094 29971 maintenance_manager.cc:643] P 21ad0cf441984a159db4c33dfcd673c1: FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57) complete. Timing: real 0.052s	user 0.023s	sys 0.019s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":19333,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:41.338683 30047 maintenance_manager.cc:419] P 21ad0cf441984a159db4c33dfcd673c1: Scheduling FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57): perf score=2.188937
I20260812 06:16:41.356467 29971 maintenance_manager.cc:643] P 21ad0cf441984a159db4c33dfcd673c1: FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57) complete. Timing: real 0.018s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6548,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:41.357410 30047 maintenance_manager.cc:419] P 21ad0cf441984a159db4c33dfcd673c1: Scheduling FlushMRSOp(48161396392a40c095b54647ea5dec57): perf score=1.000000
I20260812 06:16:41.387676 29971 maintenance_manager.cc:643] P 21ad0cf441984a159db4c33dfcd673c1: FlushMRSOp(48161396392a40c095b54647ea5dec57) complete. Timing: real 0.030s	user 0.028s	sys 0.000s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":56,"dirs.run_cpu_time_us":226,"dirs.run_wall_time_us":1501,"drs_written":1,"lbm_read_time_us":44,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1851,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:16:41.388631 30047 maintenance_manager.cc:419] P 21ad0cf441984a159db4c33dfcd673c1: Scheduling LogGCOp(48161396392a40c095b54647ea5dec57): free 132571337 bytes of WAL
I20260812 06:16:41.388929 29971 log_reader.cc:385] T 48161396392a40c095b54647ea5dec57: removed 13 log segments from log reader
I20260812 06:16:41.388998 29971 log.cc:1079] T 48161396392a40c095b54647ea5dec57 P 21ad0cf441984a159db4c33dfcd673c1: Deleting log segment in path: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397728536-29854-0/minicluster-data/ts-0-root/wals/48161396392a40c095b54647ea5dec57/wal-000000015 (ops 70-74)
I20260812 06:16:41.389052 29971 log.cc:1079] T 48161396392a40c095b54647ea5dec57 P 21ad0cf441984a159db4c33dfcd673c1: Deleting log segment in path: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397728536-29854-0/minicluster-data/ts-0-root/wals/48161396392a40c095b54647ea5dec57/wal-000000016 (ops 75-79)
I20260812 06:16:41.389112 29971 log.cc:1079] T 48161396392a40c095b54647ea5dec57 P 21ad0cf441984a159db4c33dfcd673c1: Deleting log segment in path: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397728536-29854-0/minicluster-data/ts-0-root/wals/48161396392a40c095b54647ea5dec57/wal-000000017 (ops 80-84)
I20260812 06:16:41.389154 29971 log.cc:1079] T 48161396392a40c095b54647ea5dec57 P 21ad0cf441984a159db4c33dfcd673c1: Deleting log segment in path: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397728536-29854-0/minicluster-data/ts-0-root/wals/48161396392a40c095b54647ea5dec57/wal-000000018 (ops 85-89)
I20260812 06:16:41.389194 29971 log.cc:1079] T 48161396392a40c095b54647ea5dec57 P 21ad0cf441984a159db4c33dfcd673c1: Deleting log segment in path: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397728536-29854-0/minicluster-data/ts-0-root/wals/48161396392a40c095b54647ea5dec57/wal-000000019 (ops 90-94)
I20260812 06:16:41.389233 29971 log.cc:1079] T 48161396392a40c095b54647ea5dec57 P 21ad0cf441984a159db4c33dfcd673c1: Deleting log segment in path: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397728536-29854-0/minicluster-data/ts-0-root/wals/48161396392a40c095b54647ea5dec57/wal-000000020 (ops 95-98)
I20260812 06:16:41.389268 29971 log.cc:1079] T 48161396392a40c095b54647ea5dec57 P 21ad0cf441984a159db4c33dfcd673c1: Deleting log segment in path: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397728536-29854-0/minicluster-data/ts-0-root/wals/48161396392a40c095b54647ea5dec57/wal-000000021 (ops 99-103)
I20260812 06:16:41.389305 29971 log.cc:1079] T 48161396392a40c095b54647ea5dec57 P 21ad0cf441984a159db4c33dfcd673c1: Deleting log segment in path: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397728536-29854-0/minicluster-data/ts-0-root/wals/48161396392a40c095b54647ea5dec57/wal-000000022 (ops 104-108)
I20260812 06:16:41.389341 29971 log.cc:1079] T 48161396392a40c095b54647ea5dec57 P 21ad0cf441984a159db4c33dfcd673c1: Deleting log segment in path: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397728536-29854-0/minicluster-data/ts-0-root/wals/48161396392a40c095b54647ea5dec57/wal-000000023 (ops 109-113)
I20260812 06:16:41.389379 29971 log.cc:1079] T 48161396392a40c095b54647ea5dec57 P 21ad0cf441984a159db4c33dfcd673c1: Deleting log segment in path: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397728536-29854-0/minicluster-data/ts-0-root/wals/48161396392a40c095b54647ea5dec57/wal-000000024 (ops 114-118)
I20260812 06:16:41.389416 29971 log.cc:1079] T 48161396392a40c095b54647ea5dec57 P 21ad0cf441984a159db4c33dfcd673c1: Deleting log segment in path: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397728536-29854-0/minicluster-data/ts-0-root/wals/48161396392a40c095b54647ea5dec57/wal-000000025 (ops 119-123)
I20260812 06:16:41.389451 29971 log.cc:1079] T 48161396392a40c095b54647ea5dec57 P 21ad0cf441984a159db4c33dfcd673c1: Deleting log segment in path: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397728536-29854-0/minicluster-data/ts-0-root/wals/48161396392a40c095b54647ea5dec57/wal-000000026 (ops 124-128)
I20260812 06:16:41.389487 29971 log.cc:1079] T 48161396392a40c095b54647ea5dec57 P 21ad0cf441984a159db4c33dfcd673c1: Deleting log segment in path: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397728536-29854-0/minicluster-data/ts-0-root/wals/48161396392a40c095b54647ea5dec57/wal-000000027 (ops 129-132)
I20260812 06:16:41.415355 29971 maintenance_manager.cc:643] P 21ad0cf441984a159db4c33dfcd673c1: LogGCOp(48161396392a40c095b54647ea5dec57) complete. Timing: real 0.026s	user 0.000s	sys 0.024s Metrics: {}
I20260812 06:16:41.415938 30047 maintenance_manager.cc:419] P 21ad0cf441984a159db4c33dfcd673c1: Scheduling UndoDeltaBlockGCOp(48161396392a40c095b54647ea5dec57): 493 bytes on disk
I20260812 06:16:41.416507 29971 maintenance_manager.cc:643] P 21ad0cf441984a159db4c33dfcd673c1: UndoDeltaBlockGCOp(48161396392a40c095b54647ea5dec57) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":51,"lbm_reads_lt_1ms":4}
I20260812 06:16:41.417214 30047 maintenance_manager.cc:419] P 21ad0cf441984a159db4c33dfcd673c1: Scheduling FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57): perf score=3.181125
I20260812 06:16:41.429430 29971 maintenance_manager.cc:643] P 21ad0cf441984a159db4c33dfcd673c1: FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57) complete. Timing: real 0.012s	user 0.011s	sys 0.001s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4689,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:16:41.429898 30047 maintenance_manager.cc:419] P 21ad0cf441984a159db4c33dfcd673c1: Scheduling FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57): perf score=2.188937
I20260812 06:16:41.440632 29971 maintenance_manager.cc:643] P 21ad0cf441984a159db4c33dfcd673c1: FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57) complete. Timing: real 0.011s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3707,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:41.441321 30047 maintenance_manager.cc:419] P 21ad0cf441984a159db4c33dfcd673c1: Scheduling MajorDeltaCompactionOp(48161396392a40c095b54647ea5dec57): perf score=1.000000
I20260812 06:16:41.660081 29971 maintenance_manager.cc:643] P 21ad0cf441984a159db4c33dfcd673c1: MajorDeltaCompactionOp(48161396392a40c095b54647ea5dec57) complete. Timing: real 0.219s	user 0.157s	sys 0.055s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979743,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":738,"lbm_read_time_us":12829,"lbm_reads_lt_1ms":774,"lbm_write_time_us":40987,"lbm_writes_lt_1ms":743,"mutex_wait_us":24,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":25600,"thread_start_us":86,"threads_started":1,"update_count":3500}
I20260812 06:16:41.660898 30047 maintenance_manager.cc:419] P 21ad0cf441984a159db4c33dfcd673c1: Scheduling FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57): perf score=14.095187
I20260812 06:16:41.717607 29971 maintenance_manager.cc:643] P 21ad0cf441984a159db4c33dfcd673c1: FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57) complete. Timing: real 0.056s	user 0.023s	sys 0.032s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19032,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:41.718205 30047 maintenance_manager.cc:419] P 21ad0cf441984a159db4c33dfcd673c1: Scheduling FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57): perf score=2.188937
I20260812 06:16:41.736101 29971 maintenance_manager.cc:643] P 21ad0cf441984a159db4c33dfcd673c1: FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57) complete. Timing: real 0.018s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4583,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:41.736850 30047 maintenance_manager.cc:419] P 21ad0cf441984a159db4c33dfcd673c1: Scheduling MajorDeltaCompactionOp(48161396392a40c095b54647ea5dec57): perf score=1.000000
I20260812 06:16:41.916850 29971 maintenance_manager.cc:643] P 21ad0cf441984a159db4c33dfcd673c1: MajorDeltaCompactionOp(48161396392a40c095b54647ea5dec57) complete. Timing: real 0.180s	user 0.132s	sys 0.041s 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":1536,"lbm_read_time_us":10840,"lbm_reads_lt_1ms":564,"lbm_write_time_us":32163,"lbm_writes_lt_1ms":543,"mutex_wait_us":328,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:16:41.917522 30047 maintenance_manager.cc:419] P 21ad0cf441984a159db4c33dfcd673c1: Scheduling FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57): perf score=14.095187
I20260812 06:16:41.963517 29971 maintenance_manager.cc:643] P 21ad0cf441984a159db4c33dfcd673c1: FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57) complete. Timing: real 0.046s	user 0.030s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19305,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:41.964126 30047 maintenance_manager.cc:419] P 21ad0cf441984a159db4c33dfcd673c1: Scheduling FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57): perf score=2.188937
I20260812 06:16:41.985792 29971 maintenance_manager.cc:643] P 21ad0cf441984a159db4c33dfcd673c1: FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57) complete. Timing: real 0.021s	user 0.007s	sys 0.013s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4498,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:41.986444 30047 maintenance_manager.cc:419] P 21ad0cf441984a159db4c33dfcd673c1: Scheduling MajorDeltaCompactionOp(48161396392a40c095b54647ea5dec57): perf score=1.000000
I20260812 06:16:42.166409 29971 maintenance_manager.cc:643] P 21ad0cf441984a159db4c33dfcd673c1: MajorDeltaCompactionOp(48161396392a40c095b54647ea5dec57) complete. Timing: real 0.180s	user 0.115s	sys 0.062s 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":39,"lbm_read_time_us":11472,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31124,"lbm_writes_lt_1ms":543,"mutex_wait_us":1,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2500}
I20260812 06:16:42.167222 30047 maintenance_manager.cc:419] P 21ad0cf441984a159db4c33dfcd673c1: Scheduling FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57): perf score=11.118625
I20260812 06:16:42.209438 29971 maintenance_manager.cc:643] P 21ad0cf441984a159db4c33dfcd673c1: FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57) complete. Timing: real 0.042s	user 0.032s	sys 0.009s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":17979,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:16:42.210206 30047 maintenance_manager.cc:419] P 21ad0cf441984a159db4c33dfcd673c1: Scheduling FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57): perf score=2.188937
I20260812 06:16:42.234326 29971 maintenance_manager.cc:643] P 21ad0cf441984a159db4c33dfcd673c1: FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57) complete. Timing: real 0.024s	user 0.005s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5358,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:42.234858 30047 maintenance_manager.cc:419] P 21ad0cf441984a159db4c33dfcd673c1: Scheduling FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57): perf score=2.188937
I20260812 06:16:42.245813 29971 maintenance_manager.cc:643] P 21ad0cf441984a159db4c33dfcd673c1: FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3917,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:42.246320 30047 maintenance_manager.cc:419] P 21ad0cf441984a159db4c33dfcd673c1: Scheduling MajorDeltaCompactionOp(48161396392a40c095b54647ea5dec57): perf score=1.000000
I20260812 06:16:42.439970 29971 maintenance_manager.cc:643] P 21ad0cf441984a159db4c33dfcd673c1: MajorDeltaCompactionOp(48161396392a40c095b54647ea5dec57) complete. Timing: real 0.193s	user 0.135s	sys 0.044s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774800,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":290,"lbm_read_time_us":10463,"lbm_reads_lt_1ms":573,"lbm_write_time_us":29751,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:16:42.440655 30047 maintenance_manager.cc:419] P 21ad0cf441984a159db4c33dfcd673c1: Scheduling FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57): perf score=14.095187
I20260812 06:16:42.502038 29971 maintenance_manager.cc:643] P 21ad0cf441984a159db4c33dfcd673c1: FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57) complete. Timing: real 0.061s	user 0.023s	sys 0.028s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23530,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:42.502723 30047 maintenance_manager.cc:419] P 21ad0cf441984a159db4c33dfcd673c1: Scheduling FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57): perf score=2.188937
I20260812 06:16:42.515293 29971 maintenance_manager.cc:643] P 21ad0cf441984a159db4c33dfcd673c1: FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57) complete. Timing: real 0.012s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4200,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:42.515909 30047 maintenance_manager.cc:419] P 21ad0cf441984a159db4c33dfcd673c1: Scheduling MajorDeltaCompactionOp(48161396392a40c095b54647ea5dec57): perf score=1.000000
I20260812 06:16:42.683584 29971 maintenance_manager.cc:643] P 21ad0cf441984a159db4c33dfcd673c1: MajorDeltaCompactionOp(48161396392a40c095b54647ea5dec57) complete. Timing: real 0.167s	user 0.141s	sys 0.024s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":463,"lbm_read_time_us":12049,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31861,"lbm_writes_lt_1ms":543,"mutex_wait_us":35,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4480,"update_count":2500}
I20260812 06:16:42.684381 30047 maintenance_manager.cc:419] P 21ad0cf441984a159db4c33dfcd673c1: Scheduling FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57): perf score=10.126437
I20260812 06:16:42.726742 29971 maintenance_manager.cc:643] P 21ad0cf441984a159db4c33dfcd673c1: FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57) complete. Timing: real 0.042s	user 0.026s	sys 0.014s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":18825,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:42.727324 30047 maintenance_manager.cc:419] P 21ad0cf441984a159db4c33dfcd673c1: Scheduling FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57): perf score=2.188937
I20260812 06:16:42.739358 29971 maintenance_manager.cc:643] P 21ad0cf441984a159db4c33dfcd673c1: FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57) complete. Timing: real 0.012s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4503,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:42.740029 30047 maintenance_manager.cc:419] P 21ad0cf441984a159db4c33dfcd673c1: Scheduling MajorDeltaCompactionOp(48161396392a40c095b54647ea5dec57): perf score=1.000000
I20260812 06:16:42.885638 29971 maintenance_manager.cc:643] P 21ad0cf441984a159db4c33dfcd673c1: MajorDeltaCompactionOp(48161396392a40c095b54647ea5dec57) complete. Timing: real 0.145s	user 0.109s	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":410,"lbm_read_time_us":8962,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28578,"lbm_writes_lt_1ms":443,"mutex_wait_us":30,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":15744,"update_count":2000}
I20260812 06:16:42.886440 30047 maintenance_manager.cc:419] P 21ad0cf441984a159db4c33dfcd673c1: Scheduling FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57): perf score=10.126437
I20260812 06:16:42.928575 29971 maintenance_manager.cc:643] P 21ad0cf441984a159db4c33dfcd673c1: FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57) complete. Timing: real 0.042s	user 0.016s	sys 0.016s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15620,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:42.929315 30047 maintenance_manager.cc:419] P 21ad0cf441984a159db4c33dfcd673c1: Scheduling FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57): perf score=2.188937
I20260812 06:16:42.941738 29971 maintenance_manager.cc:643] P 21ad0cf441984a159db4c33dfcd673c1: FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57) complete. Timing: real 0.012s	user 0.011s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4606,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:42.942431 30047 maintenance_manager.cc:419] P 21ad0cf441984a159db4c33dfcd673c1: Scheduling FlushMRSOp(48161396392a40c095b54647ea5dec57): perf score=1.000000
I20260812 06:16:42.975184 29971 maintenance_manager.cc:643] P 21ad0cf441984a159db4c33dfcd673c1: FlushMRSOp(48161396392a40c095b54647ea5dec57) complete. Timing: real 0.033s	user 0.030s	sys 0.000s Metrics: {"bytes_written":1234477,"cfile_init":1,"dirs.queue_time_us":68,"dirs.run_cpu_time_us":280,"dirs.run_wall_time_us":1795,"drs_written":1,"lbm_read_time_us":40,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1658,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30,"spinlock_wait_cycles":896}
I20260812 06:16:42.976009 30047 maintenance_manager.cc:419] P 21ad0cf441984a159db4c33dfcd673c1: Scheduling LogGCOp(48161396392a40c095b54647ea5dec57): free 121459753 bytes of WAL
I20260812 06:16:42.976322 29971 log_reader.cc:385] T 48161396392a40c095b54647ea5dec57: removed 12 log segments from log reader
I20260812 06:16:42.976404 29971 log.cc:1079] T 48161396392a40c095b54647ea5dec57 P 21ad0cf441984a159db4c33dfcd673c1: Deleting log segment in path: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397728536-29854-0/minicluster-data/ts-0-root/wals/48161396392a40c095b54647ea5dec57/wal-000000028 (ops 133-137)
I20260812 06:16:42.976466 29971 log.cc:1079] T 48161396392a40c095b54647ea5dec57 P 21ad0cf441984a159db4c33dfcd673c1: Deleting log segment in path: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397728536-29854-0/minicluster-data/ts-0-root/wals/48161396392a40c095b54647ea5dec57/wal-000000029 (ops 138-142)
I20260812 06:16:42.976604 29971 log.cc:1079] T 48161396392a40c095b54647ea5dec57 P 21ad0cf441984a159db4c33dfcd673c1: Deleting log segment in path: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397728536-29854-0/minicluster-data/ts-0-root/wals/48161396392a40c095b54647ea5dec57/wal-000000030 (ops 143-147)
I20260812 06:16:42.976650 29971 log.cc:1079] T 48161396392a40c095b54647ea5dec57 P 21ad0cf441984a159db4c33dfcd673c1: Deleting log segment in path: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397728536-29854-0/minicluster-data/ts-0-root/wals/48161396392a40c095b54647ea5dec57/wal-000000031 (ops 148-152)
I20260812 06:16:42.976709 29971 log.cc:1079] T 48161396392a40c095b54647ea5dec57 P 21ad0cf441984a159db4c33dfcd673c1: Deleting log segment in path: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397728536-29854-0/minicluster-data/ts-0-root/wals/48161396392a40c095b54647ea5dec57/wal-000000032 (ops 153-157)
I20260812 06:16:42.976749 29971 log.cc:1079] T 48161396392a40c095b54647ea5dec57 P 21ad0cf441984a159db4c33dfcd673c1: Deleting log segment in path: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397728536-29854-0/minicluster-data/ts-0-root/wals/48161396392a40c095b54647ea5dec57/wal-000000033 (ops 158-162)
I20260812 06:16:42.976773 29971 log.cc:1079] T 48161396392a40c095b54647ea5dec57 P 21ad0cf441984a159db4c33dfcd673c1: Deleting log segment in path: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397728536-29854-0/minicluster-data/ts-0-root/wals/48161396392a40c095b54647ea5dec57/wal-000000034 (ops 163-167)
I20260812 06:16:42.976838 29971 log.cc:1079] T 48161396392a40c095b54647ea5dec57 P 21ad0cf441984a159db4c33dfcd673c1: Deleting log segment in path: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397728536-29854-0/minicluster-data/ts-0-root/wals/48161396392a40c095b54647ea5dec57/wal-000000035 (ops 168-172)
I20260812 06:16:42.976876 29971 log.cc:1079] T 48161396392a40c095b54647ea5dec57 P 21ad0cf441984a159db4c33dfcd673c1: Deleting log segment in path: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397728536-29854-0/minicluster-data/ts-0-root/wals/48161396392a40c095b54647ea5dec57/wal-000000036 (ops 173-177)
I20260812 06:16:42.976903 29971 log.cc:1079] T 48161396392a40c095b54647ea5dec57 P 21ad0cf441984a159db4c33dfcd673c1: Deleting log segment in path: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397728536-29854-0/minicluster-data/ts-0-root/wals/48161396392a40c095b54647ea5dec57/wal-000000037 (ops 178-182)
I20260812 06:16:42.976939 29971 log.cc:1079] T 48161396392a40c095b54647ea5dec57 P 21ad0cf441984a159db4c33dfcd673c1: Deleting log segment in path: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397728536-29854-0/minicluster-data/ts-0-root/wals/48161396392a40c095b54647ea5dec57/wal-000000038 (ops 183-187)
I20260812 06:16:42.976979 29971 log.cc:1079] T 48161396392a40c095b54647ea5dec57 P 21ad0cf441984a159db4c33dfcd673c1: Deleting log segment in path: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397728536-29854-0/minicluster-data/ts-0-root/wals/48161396392a40c095b54647ea5dec57/wal-000000039 (ops 188-192)
I20260812 06:16:43.005488 29971 maintenance_manager.cc:643] P 21ad0cf441984a159db4c33dfcd673c1: LogGCOp(48161396392a40c095b54647ea5dec57) complete. Timing: real 0.029s	user 0.002s	sys 0.027s Metrics: {}
I20260812 06:16:43.006114 30047 maintenance_manager.cc:419] P 21ad0cf441984a159db4c33dfcd673c1: Scheduling FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57): perf score=4.173312
I20260812 06:16:43.023280 29971 maintenance_manager.cc:643] P 21ad0cf441984a159db4c33dfcd673c1: FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57) complete. Timing: real 0.017s	user 0.001s	sys 0.013s Metrics: {"bytes_written":5374426,"delete_count":0,"lbm_write_time_us":7052,"lbm_writes_lt_1ms":134,"reinsert_count":0,"update_count":655}
I20260812 06:16:43.023890 30047 maintenance_manager.cc:419] P 21ad0cf441984a159db4c33dfcd673c1: Scheduling LogGCOp(48161396392a40c095b54647ea5dec57): free 11564893 bytes of WAL
I20260812 06:16:43.024164 29971 log_reader.cc:385] T 48161396392a40c095b54647ea5dec57: removed 1 log segments from log reader
I20260812 06:16:43.024225 29971 log.cc:1079] T 48161396392a40c095b54647ea5dec57 P 21ad0cf441984a159db4c33dfcd673c1: Deleting log segment in path: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515397728536-29854-0/minicluster-data/ts-0-root/wals/48161396392a40c095b54647ea5dec57/wal-000000040 (ops 193-196)
I20260812 06:16:43.027010 29971 maintenance_manager.cc:643] P 21ad0cf441984a159db4c33dfcd673c1: LogGCOp(48161396392a40c095b54647ea5dec57) complete. Timing: real 0.003s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:16:43.027413 30047 maintenance_manager.cc:419] P 21ad0cf441984a159db4c33dfcd673c1: Scheduling UndoDeltaBlockGCOp(48161396392a40c095b54647ea5dec57): 472 bytes on disk
I20260812 06:16:43.027963 29971 maintenance_manager.cc:643] P 21ad0cf441984a159db4c33dfcd673c1: UndoDeltaBlockGCOp(48161396392a40c095b54647ea5dec57) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":75,"lbm_reads_lt_1ms":4}
I20260812 06:16:43.028524 30047 maintenance_manager.cc:419] P 21ad0cf441984a159db4c33dfcd673c1: Scheduling FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57): perf score=1.196750
I20260812 06:16:43.040529 29971 maintenance_manager.cc:643] P 21ad0cf441984a159db4c33dfcd673c1: FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":2830880,"delete_count":0,"lbm_write_time_us":4277,"lbm_writes_lt_1ms":72,"reinsert_count":0,"update_count":345}
I20260812 06:16:43.041111 30047 maintenance_manager.cc:419] P 21ad0cf441984a159db4c33dfcd673c1: Scheduling MajorDeltaCompactionOp(48161396392a40c095b54647ea5dec57): perf score=1.000000
I20260812 06:16:43.108309 29854 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.120s	user 1.886s	sys 0.122s
I20260812 06:16:43.201071 29854 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.092s	user 0.003s	sys 0.000s
I20260812 06:16:43.201732 29854 tablet_server.cc:179] TabletServer@127.29.39.129:0 shutting down...
I20260812 06:16:43.203469 29971 maintenance_manager.cc:643] P 21ad0cf441984a159db4c33dfcd673c1: MajorDeltaCompactionOp(48161396392a40c095b54647ea5dec57) complete. Timing: real 0.162s	user 0.127s	sys 0.035s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877322,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":392,"lbm_read_time_us":10640,"lbm_reads_lt_1ms":662,"lbm_write_time_us":33982,"lbm_writes_lt_1ms":643,"mutex_wait_us":46,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":61952,"thread_start_us":71,"threads_started":1,"update_count":3000}
I20260812 06:16:43.204216 30047 maintenance_manager.cc:419] P 21ad0cf441984a159db4c33dfcd673c1: Scheduling FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57): perf score=6.157687
I20260812 06:16:43.229434 29971 maintenance_manager.cc:643] P 21ad0cf441984a159db4c33dfcd673c1: FlushDeltaMemStoresOp(48161396392a40c095b54647ea5dec57) complete. Timing: real 0.025s	user 0.020s	sys 0.004s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":10581,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:16:43.230086 29854 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:16:43.230549 29854 tablet_replica.cc:333] T 48161396392a40c095b54647ea5dec57 P 21ad0cf441984a159db4c33dfcd673c1: stopping tablet replica
I20260812 06:16:43.230811 29854 raft_consensus.cc:2243] T 48161396392a40c095b54647ea5dec57 P 21ad0cf441984a159db4c33dfcd673c1 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:43.231067 29854 raft_consensus.cc:2272] T 48161396392a40c095b54647ea5dec57 P 21ad0cf441984a159db4c33dfcd673c1 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:43.247006 29854 tablet_server.cc:196] TabletServer@127.29.39.129:0 shutdown complete.
I20260812 06:16:43.257089 29854 master.cc:562] Master@127.29.39.190:40587 shutting down...
I20260812 06:16:43.261003 29854 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 9b7d7b2750614138b8d2bababd531c38 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:43.261234 29854 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 9b7d7b2750614138b8d2bababd531c38 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:43.261339 29854 tablet_replica.cc:333] T 00000000000000000000000000000000 P 9b7d7b2750614138b8d2bababd531c38: stopping tablet replica
I20260812 06:16:43.273955 29854 master.cc:584] Master@127.29.39.190:40587 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5618 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:16:43.357935 29854 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.29.39.190:41601
I20260812 06:16:43.358353 29854 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:43.361254 30087 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:16:43.361315 29854 server_base.cc:1061] running on GCE node
W20260812 06:16:43.361440 30085 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:16:43.361377 30084 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:16:43.361852 29854 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:43.361896 29854 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:16:43.361912 29854 hybrid_clock.cc:648] HybridClock initialized: now 1786515403361912 us; error 0 us; skew 500 ppm
I20260812 06:16:43.362785 29854 webserver.cc:533] Webserver started at http://127.29.39.190:37481/ using document root <none> and password file <none>
I20260812 06:16:43.362934 29854 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:43.363003 29854 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:43.363060 29854 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:43.363423 29854 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397728536-29854-0/minicluster-data/master-0-root/instance:
uuid: "1d6281ea68bb45ca98891b97f29ccc2e"
format_stamp: "Formatted at 2026-08-12 06:16:43 on dist-test-slave-cbsf"
I20260812 06:16:43.365059 29854 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:16:43.366062 30093 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:43.366314 29854 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:16:43.366381 29854 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397728536-29854-0/minicluster-data/master-0-root
uuid: "1d6281ea68bb45ca98891b97f29ccc2e"
format_stamp: "Formatted at 2026-08-12 06:16:43 on dist-test-slave-cbsf"
I20260812 06:16:43.366446 29854 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397728536-29854-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397728536-29854-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397728536-29854-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:16:43.375269 29854 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:43.375638 29854 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:43.380141 29854 rpc_server.cc:307] RPC server started. Bound to: 127.29.39.190:41601
I20260812 06:16:43.381636 30156 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:16:43.381831 30155 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.29.39.190:41601 every 8 connection(s)
I20260812 06:16:43.400091 30156 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 1d6281ea68bb45ca98891b97f29ccc2e: Bootstrap starting.
I20260812 06:16:43.401144 30156 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 1d6281ea68bb45ca98891b97f29ccc2e: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:43.402310 30156 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 1d6281ea68bb45ca98891b97f29ccc2e: No bootstrap required, opened a new log
I20260812 06:16:43.402829 30156 raft_consensus.cc:359] T 00000000000000000000000000000000 P 1d6281ea68bb45ca98891b97f29ccc2e [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1d6281ea68bb45ca98891b97f29ccc2e" member_type: VOTER }
I20260812 06:16:43.402927 30156 raft_consensus.cc:385] T 00000000000000000000000000000000 P 1d6281ea68bb45ca98891b97f29ccc2e [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:43.402978 30156 raft_consensus.cc:740] T 00000000000000000000000000000000 P 1d6281ea68bb45ca98891b97f29ccc2e [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 1d6281ea68bb45ca98891b97f29ccc2e, State: Initialized, Role: FOLLOWER
I20260812 06:16:43.403216 30156 consensus_queue.cc:260] T 00000000000000000000000000000000 P 1d6281ea68bb45ca98891b97f29ccc2e [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: "1d6281ea68bb45ca98891b97f29ccc2e" member_type: VOTER }
I20260812 06:16:43.403331 30156 raft_consensus.cc:399] T 00000000000000000000000000000000 P 1d6281ea68bb45ca98891b97f29ccc2e [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:43.403358 30156 raft_consensus.cc:493] T 00000000000000000000000000000000 P 1d6281ea68bb45ca98891b97f29ccc2e [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:43.403398 30156 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 1d6281ea68bb45ca98891b97f29ccc2e [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:43.404145 30156 raft_consensus.cc:515] T 00000000000000000000000000000000 P 1d6281ea68bb45ca98891b97f29ccc2e [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1d6281ea68bb45ca98891b97f29ccc2e" member_type: VOTER }
I20260812 06:16:43.404263 30156 leader_election.cc:304] T 00000000000000000000000000000000 P 1d6281ea68bb45ca98891b97f29ccc2e [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: 1d6281ea68bb45ca98891b97f29ccc2e; no voters: 
I20260812 06:16:43.404419 30156 leader_election.cc:290] T 00000000000000000000000000000000 P 1d6281ea68bb45ca98891b97f29ccc2e [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:43.404620 30159 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 1d6281ea68bb45ca98891b97f29ccc2e [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:43.404865 30159 raft_consensus.cc:697] T 00000000000000000000000000000000 P 1d6281ea68bb45ca98891b97f29ccc2e [term 1 LEADER]: Becoming Leader. State: Replica: 1d6281ea68bb45ca98891b97f29ccc2e, State: Running, Role: LEADER
I20260812 06:16:43.405066 30159 consensus_queue.cc:237] T 00000000000000000000000000000000 P 1d6281ea68bb45ca98891b97f29ccc2e [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: "1d6281ea68bb45ca98891b97f29ccc2e" member_type: VOTER }
I20260812 06:16:43.405097 30156 sys_catalog.cc:565] T 00000000000000000000000000000000 P 1d6281ea68bb45ca98891b97f29ccc2e [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:16:43.405522 30160 sys_catalog.cc:455] T 00000000000000000000000000000000 P 1d6281ea68bb45ca98891b97f29ccc2e [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "1d6281ea68bb45ca98891b97f29ccc2e" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1d6281ea68bb45ca98891b97f29ccc2e" member_type: VOTER } }
I20260812 06:16:43.405586 30161 sys_catalog.cc:455] T 00000000000000000000000000000000 P 1d6281ea68bb45ca98891b97f29ccc2e [sys.catalog]: SysCatalogTable state changed. Reason: New leader 1d6281ea68bb45ca98891b97f29ccc2e. Latest consensus state: current_term: 1 leader_uuid: "1d6281ea68bb45ca98891b97f29ccc2e" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1d6281ea68bb45ca98891b97f29ccc2e" member_type: VOTER } }
I20260812 06:16:43.405696 30161 sys_catalog.cc:458] T 00000000000000000000000000000000 P 1d6281ea68bb45ca98891b97f29ccc2e [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:43.405686 30160 sys_catalog.cc:458] T 00000000000000000000000000000000 P 1d6281ea68bb45ca98891b97f29ccc2e [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:43.406339 30164 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:16:43.407419 30164 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:16:43.407698 29854 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:16:43.409574 30164 catalog_manager.cc:1383] Generated new cluster ID: afea2e43deca4c3ca092aabcd06652ed
I20260812 06:16:43.409646 30164 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:16:43.418846 30164 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:16:43.419446 30164 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:16:43.424400 30164 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 1d6281ea68bb45ca98891b97f29ccc2e: Generated new TSK 0
I20260812 06:16:43.424675 30164 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:16:43.440485 29854 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:43.442730 30183 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:16:43.442756 30185 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:16:43.442745 30187 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:16:43.442839 29854 server_base.cc:1061] running on GCE node
I20260812 06:16:43.443192 29854 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:43.443289 29854 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:16:43.443325 29854 hybrid_clock.cc:648] HybridClock initialized: now 1786515403443324 us; error 0 us; skew 500 ppm
I20260812 06:16:43.444244 29854 webserver.cc:533] Webserver started at http://127.29.39.129:34963/ using document root <none> and password file <none>
I20260812 06:16:43.444430 29854 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:43.444511 29854 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:43.444597 29854 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:43.445065 29854 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397728536-29854-0/minicluster-data/ts-0-root/instance:
uuid: "542b409cf89a4acf81ec0f700653ed36"
format_stamp: "Formatted at 2026-08-12 06:16:43 on dist-test-slave-cbsf"
I20260812 06:16:43.446683 29854 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:16:43.447758 30192 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:43.448108 29854 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:16:43.448200 29854 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397728536-29854-0/minicluster-data/ts-0-root
uuid: "542b409cf89a4acf81ec0f700653ed36"
format_stamp: "Formatted at 2026-08-12 06:16:43 on dist-test-slave-cbsf"
I20260812 06:16:43.448292 29854 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397728536-29854-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397728536-29854-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397728536-29854-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:16:43.458657 29854 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:43.459105 29854 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:43.459456 29854 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:16:43.459969 29854 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:16:43.460032 29854 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:43.460115 29854 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:16:43.460167 29854 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:43.465305 29854 rpc_server.cc:307] RPC server started. Bound to: 127.29.39.129:34983
I20260812 06:16:43.465358 30268 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.29.39.129:34983 every 8 connection(s)
I20260812 06:16:43.475478 30269 heartbeater.cc:344] Connected to a master server at 127.29.39.190:41601
I20260812 06:16:43.475617 30269 heartbeater.cc:461] Registering TS with master...
I20260812 06:16:43.475847 30269 heartbeater.cc:507] Master 127.29.39.190:41601 requested a full tablet report, sending...
I20260812 06:16:43.476577 30112 ts_manager.cc:194] Registered new tserver with Master: 542b409cf89a4acf81ec0f700653ed36 (127.29.39.129:34983)
I20260812 06:16:43.477034 29854 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.011149227s
I20260812 06:16:43.477401 30112 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:59086
I20260812 06:16:43.484786 30112 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:59094:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:16:43.494115 30221 tablet_service.cc:1511] Processing CreateTablet for tablet 609b6737a2ab4a77ade894eabd2c384d (DEFAULT_TABLE table=heavy-update-compaction-test [id=0e887621d3c84162bd274d54dddfd96c]), partition=
I20260812 06:16:43.494428 30221 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 609b6737a2ab4a77ade894eabd2c384d. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:16:43.496683 30285 tablet_bootstrap.cc:492] T 609b6737a2ab4a77ade894eabd2c384d P 542b409cf89a4acf81ec0f700653ed36: Bootstrap starting.
I20260812 06:16:43.497625 30285 tablet_bootstrap.cc:654] T 609b6737a2ab4a77ade894eabd2c384d P 542b409cf89a4acf81ec0f700653ed36: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:43.498798 30285 tablet_bootstrap.cc:492] T 609b6737a2ab4a77ade894eabd2c384d P 542b409cf89a4acf81ec0f700653ed36: No bootstrap required, opened a new log
I20260812 06:16:43.498915 30285 ts_tablet_manager.cc:1403] T 609b6737a2ab4a77ade894eabd2c384d P 542b409cf89a4acf81ec0f700653ed36: Time spent bootstrapping tablet: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:16:43.499418 30285 raft_consensus.cc:359] T 609b6737a2ab4a77ade894eabd2c384d P 542b409cf89a4acf81ec0f700653ed36 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "542b409cf89a4acf81ec0f700653ed36" member_type: VOTER last_known_addr { host: "127.29.39.129" port: 34983 } }
I20260812 06:16:43.499545 30285 raft_consensus.cc:385] T 609b6737a2ab4a77ade894eabd2c384d P 542b409cf89a4acf81ec0f700653ed36 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:43.499626 30285 raft_consensus.cc:740] T 609b6737a2ab4a77ade894eabd2c384d P 542b409cf89a4acf81ec0f700653ed36 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 542b409cf89a4acf81ec0f700653ed36, State: Initialized, Role: FOLLOWER
I20260812 06:16:43.499809 30285 consensus_queue.cc:260] T 609b6737a2ab4a77ade894eabd2c384d P 542b409cf89a4acf81ec0f700653ed36 [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: "542b409cf89a4acf81ec0f700653ed36" member_type: VOTER last_known_addr { host: "127.29.39.129" port: 34983 } }
I20260812 06:16:43.499919 30285 raft_consensus.cc:399] T 609b6737a2ab4a77ade894eabd2c384d P 542b409cf89a4acf81ec0f700653ed36 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:43.499974 30285 raft_consensus.cc:493] T 609b6737a2ab4a77ade894eabd2c384d P 542b409cf89a4acf81ec0f700653ed36 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:43.500037 30285 raft_consensus.cc:3060] T 609b6737a2ab4a77ade894eabd2c384d P 542b409cf89a4acf81ec0f700653ed36 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:43.500910 30285 raft_consensus.cc:515] T 609b6737a2ab4a77ade894eabd2c384d P 542b409cf89a4acf81ec0f700653ed36 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "542b409cf89a4acf81ec0f700653ed36" member_type: VOTER last_known_addr { host: "127.29.39.129" port: 34983 } }
I20260812 06:16:43.501062 30285 leader_election.cc:304] T 609b6737a2ab4a77ade894eabd2c384d P 542b409cf89a4acf81ec0f700653ed36 [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: 542b409cf89a4acf81ec0f700653ed36; no voters: 
I20260812 06:16:43.501313 30285 leader_election.cc:290] T 609b6737a2ab4a77ade894eabd2c384d P 542b409cf89a4acf81ec0f700653ed36 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:43.501513 30287 raft_consensus.cc:2804] T 609b6737a2ab4a77ade894eabd2c384d P 542b409cf89a4acf81ec0f700653ed36 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:43.501683 30285 ts_tablet_manager.cc:1434] T 609b6737a2ab4a77ade894eabd2c384d P 542b409cf89a4acf81ec0f700653ed36: Time spent starting tablet: real 0.003s	user 0.000s	sys 0.003s
I20260812 06:16:43.501688 30269 heartbeater.cc:499] Master 127.29.39.190:41601 was elected leader, sending a full tablet report...
I20260812 06:16:43.501770 30287 raft_consensus.cc:697] T 609b6737a2ab4a77ade894eabd2c384d P 542b409cf89a4acf81ec0f700653ed36 [term 1 LEADER]: Becoming Leader. State: Replica: 542b409cf89a4acf81ec0f700653ed36, State: Running, Role: LEADER
I20260812 06:16:43.501972 30287 consensus_queue.cc:237] T 609b6737a2ab4a77ade894eabd2c384d P 542b409cf89a4acf81ec0f700653ed36 [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: "542b409cf89a4acf81ec0f700653ed36" member_type: VOTER last_known_addr { host: "127.29.39.129" port: 34983 } }
I20260812 06:16:43.503624 30112 catalog_manager.cc:5719] T 609b6737a2ab4a77ade894eabd2c384d P 542b409cf89a4acf81ec0f700653ed36 reported cstate change: term changed from 0 to 1, leader changed from <none> to 542b409cf89a4acf81ec0f700653ed36 (127.29.39.129). New cstate: current_term: 1 leader_uuid: "542b409cf89a4acf81ec0f700653ed36" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "542b409cf89a4acf81ec0f700653ed36" member_type: VOTER last_known_addr { host: "127.29.39.129" port: 34983 } health_report { overall_health: HEALTHY } } }
I20260812 06:16:43.562290 29854 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.052s	user 0.019s	sys 0.004s
I20260812 06:16:43.716482 30271 maintenance_manager.cc:419] P 542b409cf89a4acf81ec0f700653ed36: Scheduling FlushMRSOp(609b6737a2ab4a77ade894eabd2c384d): perf score=19.054940
I20260812 06:16:43.877923 30197 maintenance_manager.cc:643] P 542b409cf89a4acf81ec0f700653ed36: FlushMRSOp(609b6737a2ab4a77ade894eabd2c384d) complete. Timing: real 0.161s	user 0.139s	sys 0.020s Metrics: {"bytes_written":12307490,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":99,"dirs.run_cpu_time_us":246,"dirs.run_wall_time_us":1043,"drs_written":1,"lbm_read_time_us":40,"lbm_reads_lt_1ms":4,"lbm_write_time_us":39507,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1500}
I20260812 06:16:43.878654 30271 maintenance_manager.cc:419] P 542b409cf89a4acf81ec0f700653ed36: Scheduling LogGCOp(609b6737a2ab4a77ade894eabd2c384d): free 20743880 bytes of WAL
I20260812 06:16:43.879002 30197 log_reader.cc:385] T 609b6737a2ab4a77ade894eabd2c384d: removed 2 log segments from log reader
I20260812 06:16:43.879066 30197 log.cc:1079] T 609b6737a2ab4a77ade894eabd2c384d P 542b409cf89a4acf81ec0f700653ed36: Deleting log segment in path: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397728536-29854-0/minicluster-data/ts-0-root/wals/609b6737a2ab4a77ade894eabd2c384d/wal-000000001 (ops 1-6)
I20260812 06:16:43.879124 30197 log.cc:1079] T 609b6737a2ab4a77ade894eabd2c384d P 542b409cf89a4acf81ec0f700653ed36: Deleting log segment in path: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397728536-29854-0/minicluster-data/ts-0-root/wals/609b6737a2ab4a77ade894eabd2c384d/wal-000000002 (ops 7-11)
I20260812 06:16:43.884915 30197 maintenance_manager.cc:643] P 542b409cf89a4acf81ec0f700653ed36: LogGCOp(609b6737a2ab4a77ade894eabd2c384d) complete. Timing: real 0.006s	user 0.000s	sys 0.006s Metrics: {}
I20260812 06:16:43.885288 30271 maintenance_manager.cc:419] P 542b409cf89a4acf81ec0f700653ed36: Scheduling FlushDeltaMemStoresOp(609b6737a2ab4a77ade894eabd2c384d): perf score=2.188937
I20260812 06:16:43.898712 30197 maintenance_manager.cc:643] P 542b409cf89a4acf81ec0f700653ed36: FlushDeltaMemStoresOp(609b6737a2ab4a77ade894eabd2c384d) complete. Timing: real 0.013s	user 0.004s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4861,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:43.899183 30271 maintenance_manager.cc:419] P 542b409cf89a4acf81ec0f700653ed36: Scheduling MajorDeltaCompactionOp(609b6737a2ab4a77ade894eabd2c384d): perf score=1.000000
I20260812 06:16:44.044070 30197 maintenance_manager.cc:643] P 542b409cf89a4acf81ec0f700653ed36: MajorDeltaCompactionOp(609b6737a2ab4a77ade894eabd2c384d) complete. Timing: real 0.145s	user 0.112s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":491,"lbm_read_time_us":9081,"lbm_reads_lt_1ms":464,"lbm_write_time_us":25803,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"thread_start_us":384,"threads_started":5,"update_count":2000}
I20260812 06:16:44.044867 30271 maintenance_manager.cc:419] P 542b409cf89a4acf81ec0f700653ed36: Scheduling FlushDeltaMemStoresOp(609b6737a2ab4a77ade894eabd2c384d): perf score=10.126437
I20260812 06:16:44.077235 30197 maintenance_manager.cc:643] P 542b409cf89a4acf81ec0f700653ed36: FlushDeltaMemStoresOp(609b6737a2ab4a77ade894eabd2c384d) complete. Timing: real 0.032s	user 0.019s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13731,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:44.077718 30271 maintenance_manager.cc:419] P 542b409cf89a4acf81ec0f700653ed36: Scheduling UndoDeltaBlockGCOp(609b6737a2ab4a77ade894eabd2c384d): 16411391 bytes on disk
I20260812 06:16:44.078130 30197 maintenance_manager.cc:643] P 542b409cf89a4acf81ec0f700653ed36: UndoDeltaBlockGCOp(609b6737a2ab4a77ade894eabd2c384d) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":62,"lbm_reads_lt_1ms":4}
I20260812 06:16:44.078598 30271 maintenance_manager.cc:419] P 542b409cf89a4acf81ec0f700653ed36: Scheduling FlushDeltaMemStoresOp(609b6737a2ab4a77ade894eabd2c384d): perf score=2.188937
I20260812 06:16:44.094309 30197 maintenance_manager.cc:643] P 542b409cf89a4acf81ec0f700653ed36: FlushDeltaMemStoresOp(609b6737a2ab4a77ade894eabd2c384d) complete. Timing: real 0.015s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5751,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:44.094956 30271 maintenance_manager.cc:419] P 542b409cf89a4acf81ec0f700653ed36: Scheduling MajorDeltaCompactionOp(609b6737a2ab4a77ade894eabd2c384d): perf score=1.000000
I20260812 06:16:44.227981 30197 maintenance_manager.cc:643] P 542b409cf89a4acf81ec0f700653ed36: MajorDeltaCompactionOp(609b6737a2ab4a77ade894eabd2c384d) complete. Timing: real 0.133s	user 0.108s	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":830,"lbm_read_time_us":9566,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23804,"lbm_writes_lt_1ms":443,"mutex_wait_us":293,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":14848,"update_count":2000}
I20260812 06:16:44.228601 30271 maintenance_manager.cc:419] P 542b409cf89a4acf81ec0f700653ed36: Scheduling FlushDeltaMemStoresOp(609b6737a2ab4a77ade894eabd2c384d): perf score=10.126437
I20260812 06:16:44.280907 30197 maintenance_manager.cc:643] P 542b409cf89a4acf81ec0f700653ed36: FlushDeltaMemStoresOp(609b6737a2ab4a77ade894eabd2c384d) complete. Timing: real 0.052s	user 0.035s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16021,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:44.281454 30271 maintenance_manager.cc:419] P 542b409cf89a4acf81ec0f700653ed36: Scheduling FlushDeltaMemStoresOp(609b6737a2ab4a77ade894eabd2c384d): perf score=2.188937
I20260812 06:16:44.292742 30197 maintenance_manager.cc:643] P 542b409cf89a4acf81ec0f700653ed36: FlushDeltaMemStoresOp(609b6737a2ab4a77ade894eabd2c384d) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4288,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:44.293179 30271 maintenance_manager.cc:419] P 542b409cf89a4acf81ec0f700653ed36: Scheduling MajorDeltaCompactionOp(609b6737a2ab4a77ade894eabd2c384d): perf score=1.000000
I20260812 06:16:44.450562 30197 maintenance_manager.cc:643] P 542b409cf89a4acf81ec0f700653ed36: MajorDeltaCompactionOp(609b6737a2ab4a77ade894eabd2c384d) complete. Timing: real 0.157s	user 0.110s	sys 0.046s 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":986,"lbm_read_time_us":11597,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24456,"lbm_writes_lt_1ms":443,"mutex_wait_us":297,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":13568,"update_count":2000}
I20260812 06:16:44.451301 30271 maintenance_manager.cc:419] P 542b409cf89a4acf81ec0f700653ed36: Scheduling FlushDeltaMemStoresOp(609b6737a2ab4a77ade894eabd2c384d): perf score=10.126437
I20260812 06:16:44.487305 30197 maintenance_manager.cc:643] P 542b409cf89a4acf81ec0f700653ed36: FlushDeltaMemStoresOp(609b6737a2ab4a77ade894eabd2c384d) complete. Timing: real 0.036s	user 0.016s	sys 0.017s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":15472,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:44.487854 30271 maintenance_manager.cc:419] P 542b409cf89a4acf81ec0f700653ed36: Scheduling FlushDeltaMemStoresOp(609b6737a2ab4a77ade894eabd2c384d): perf score=2.188937
I20260812 06:16:44.498577 30197 maintenance_manager.cc:643] P 542b409cf89a4acf81ec0f700653ed36: FlushDeltaMemStoresOp(609b6737a2ab4a77ade894eabd2c384d) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4104,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:44.499058 30271 maintenance_manager.cc:419] P 542b409cf89a4acf81ec0f700653ed36: Scheduling MajorDeltaCompactionOp(609b6737a2ab4a77ade894eabd2c384d): perf score=1.000000
I20260812 06:16:44.624785 30197 maintenance_manager.cc:643] P 542b409cf89a4acf81ec0f700653ed36: MajorDeltaCompactionOp(609b6737a2ab4a77ade894eabd2c384d) complete. Timing: real 0.126s	user 0.110s	sys 0.016s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672280,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":214,"lbm_read_time_us":8060,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24368,"lbm_writes_lt_1ms":443,"mutex_wait_us":23,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11392,"update_count":2000}
I20260812 06:16:44.628374 30271 maintenance_manager.cc:419] P 542b409cf89a4acf81ec0f700653ed36: Scheduling FlushDeltaMemStoresOp(609b6737a2ab4a77ade894eabd2c384d): perf score=10.126437
I20260812 06:16:44.665287 30197 maintenance_manager.cc:643] P 542b409cf89a4acf81ec0f700653ed36: FlushDeltaMemStoresOp(609b6737a2ab4a77ade894eabd2c384d) complete. Timing: real 0.036s	user 0.025s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15640,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:16:44.665894 30271 maintenance_manager.cc:419] P 542b409cf89a4acf81ec0f700653ed36: Scheduling FlushDeltaMemStoresOp(609b6737a2ab4a77ade894eabd2c384d): perf score=2.188937
I20260812 06:16:44.680184 30197 maintenance_manager.cc:643] P 542b409cf89a4acf81ec0f700653ed36: FlushDeltaMemStoresOp(609b6737a2ab4a77ade894eabd2c384d) complete. Timing: real 0.014s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5812,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:44.680680 30271 maintenance_manager.cc:419] P 542b409cf89a4acf81ec0f700653ed36: Scheduling MajorDeltaCompactionOp(609b6737a2ab4a77ade894eabd2c384d): perf score=1.000000
I20260812 06:16:44.816948 30197 maintenance_manager.cc:643] P 542b409cf89a4acf81ec0f700653ed36: MajorDeltaCompactionOp(609b6737a2ab4a77ade894eabd2c384d) complete. Timing: real 0.136s	user 0.106s	sys 0.023s 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":1046,"lbm_read_time_us":10521,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24970,"lbm_writes_lt_1ms":443,"mutex_wait_us":47,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":23040,"update_count":2000}
I20260812 06:16:44.817680 30271 maintenance_manager.cc:419] P 542b409cf89a4acf81ec0f700653ed36: Scheduling FlushDeltaMemStoresOp(609b6737a2ab4a77ade894eabd2c384d): perf score=10.126437
I20260812 06:16:44.871910 30197 maintenance_manager.cc:643] P 542b409cf89a4acf81ec0f700653ed36: FlushDeltaMemStoresOp(609b6737a2ab4a77ade894eabd2c384d) complete. Timing: real 0.054s	user 0.019s	sys 0.024s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16364,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:44.872522 30271 maintenance_manager.cc:419] P 542b409cf89a4acf81ec0f700653ed36: Scheduling FlushDeltaMemStoresOp(609b6737a2ab4a77ade894eabd2c384d): perf score=2.188937
I20260812 06:16:44.883701 30197 maintenance_manager.cc:643] P 542b409cf89a4acf81ec0f700653ed36: FlushDeltaMemStoresOp(609b6737a2ab4a77ade894eabd2c384d) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4363,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:44.884222 30271 maintenance_manager.cc:419] P 542b409cf89a4acf81ec0f700653ed36: Scheduling MajorDeltaCompactionOp(609b6737a2ab4a77ade894eabd2c384d): perf score=1.000000
I20260812 06:16:45.040841 30197 maintenance_manager.cc:643] P 542b409cf89a4acf81ec0f700653ed36: MajorDeltaCompactionOp(609b6737a2ab4a77ade894eabd2c384d) complete. Timing: real 0.156s	user 0.112s	sys 0.044s 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":238,"lbm_read_time_us":10709,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23294,"lbm_writes_lt_1ms":443,"mutex_wait_us":49,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12032,"update_count":2000}
I20260812 06:16:45.041574 30271 maintenance_manager.cc:419] P 542b409cf89a4acf81ec0f700653ed36: Scheduling FlushDeltaMemStoresOp(609b6737a2ab4a77ade894eabd2c384d): perf score=10.126437
I20260812 06:16:45.087715 30197 maintenance_manager.cc:643] P 542b409cf89a4acf81ec0f700653ed36: FlushDeltaMemStoresOp(609b6737a2ab4a77ade894eabd2c384d) complete. Timing: real 0.046s	user 0.027s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":21145,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:16:45.088370 30271 maintenance_manager.cc:419] P 542b409cf89a4acf81ec0f700653ed36: Scheduling FlushDeltaMemStoresOp(609b6737a2ab4a77ade894eabd2c384d): perf score=2.188937
I20260812 06:16:45.104452 30197 maintenance_manager.cc:643] P 542b409cf89a4acf81ec0f700653ed36: FlushDeltaMemStoresOp(609b6737a2ab4a77ade894eabd2c384d) complete. Timing: real 0.016s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5506,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:45.105079 30271 maintenance_manager.cc:419] P 542b409cf89a4acf81ec0f700653ed36: Scheduling FlushMRSOp(609b6737a2ab4a77ade894eabd2c384d): perf score=1.000000
I20260812 06:16:45.143734 30197 maintenance_manager.cc:643] P 542b409cf89a4acf81ec0f700653ed36: FlushMRSOp(609b6737a2ab4a77ade894eabd2c384d) complete. Timing: real 0.038s	user 0.021s	sys 0.004s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":65,"dirs.run_cpu_time_us":261,"dirs.run_wall_time_us":1720,"drs_written":1,"lbm_read_time_us":42,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1811,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:16:45.144539 30271 maintenance_manager.cc:419] P 542b409cf89a4acf81ec0f700653ed36: Scheduling UndoDeltaBlockGCOp(609b6737a2ab4a77ade894eabd2c384d): 462 bytes on disk
I20260812 06:16:45.144958 30197 maintenance_manager.cc:643] P 542b409cf89a4acf81ec0f700653ed36: UndoDeltaBlockGCOp(609b6737a2ab4a77ade894eabd2c384d) 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:16:45.145634 30271 maintenance_manager.cc:419] P 542b409cf89a4acf81ec0f700653ed36: Scheduling FlushDeltaMemStoresOp(609b6737a2ab4a77ade894eabd2c384d): perf score=3.181125
I20260812 06:16:45.166492 30197 maintenance_manager.cc:643] P 542b409cf89a4acf81ec0f700653ed36: FlushDeltaMemStoresOp(609b6737a2ab4a77ade894eabd2c384d) complete. Timing: real 0.021s	user 0.006s	sys 0.013s Metrics: {"bytes_written":4512902,"delete_count":0,"lbm_write_time_us":4430,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:16:45.167099 30271 maintenance_manager.cc:419] P 542b409cf89a4acf81ec0f700653ed36: Scheduling LogGCOp(609b6737a2ab4a77ade894eabd2c384d): free 120553325 bytes of WAL
I20260812 06:16:45.167378 30197 log_reader.cc:385] T 609b6737a2ab4a77ade894eabd2c384d: removed 12 log segments from log reader
I20260812 06:16:45.167449 30197 log.cc:1079] T 609b6737a2ab4a77ade894eabd2c384d P 542b409cf89a4acf81ec0f700653ed36: Deleting log segment in path: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397728536-29854-0/minicluster-data/ts-0-root/wals/609b6737a2ab4a77ade894eabd2c384d/wal-000000003 (ops 12-16)
I20260812 06:16:45.167506 30197 log.cc:1079] T 609b6737a2ab4a77ade894eabd2c384d P 542b409cf89a4acf81ec0f700653ed36: Deleting log segment in path: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397728536-29854-0/minicluster-data/ts-0-root/wals/609b6737a2ab4a77ade894eabd2c384d/wal-000000004 (ops 17-21)
I20260812 06:16:45.167567 30197 log.cc:1079] T 609b6737a2ab4a77ade894eabd2c384d P 542b409cf89a4acf81ec0f700653ed36: Deleting log segment in path: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397728536-29854-0/minicluster-data/ts-0-root/wals/609b6737a2ab4a77ade894eabd2c384d/wal-000000005 (ops 22-26)
I20260812 06:16:45.167620 30197 log.cc:1079] T 609b6737a2ab4a77ade894eabd2c384d P 542b409cf89a4acf81ec0f700653ed36: Deleting log segment in path: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397728536-29854-0/minicluster-data/ts-0-root/wals/609b6737a2ab4a77ade894eabd2c384d/wal-000000006 (ops 27-31)
I20260812 06:16:45.167652 30197 log.cc:1079] T 609b6737a2ab4a77ade894eabd2c384d P 542b409cf89a4acf81ec0f700653ed36: Deleting log segment in path: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397728536-29854-0/minicluster-data/ts-0-root/wals/609b6737a2ab4a77ade894eabd2c384d/wal-000000007 (ops 32-36)
I20260812 06:16:45.167708 30197 log.cc:1079] T 609b6737a2ab4a77ade894eabd2c384d P 542b409cf89a4acf81ec0f700653ed36: Deleting log segment in path: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397728536-29854-0/minicluster-data/ts-0-root/wals/609b6737a2ab4a77ade894eabd2c384d/wal-000000008 (ops 37-40)
I20260812 06:16:45.167740 30197 log.cc:1079] T 609b6737a2ab4a77ade894eabd2c384d P 542b409cf89a4acf81ec0f700653ed36: Deleting log segment in path: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397728536-29854-0/minicluster-data/ts-0-root/wals/609b6737a2ab4a77ade894eabd2c384d/wal-000000009 (ops 41-45)
I20260812 06:16:45.167785 30197 log.cc:1079] T 609b6737a2ab4a77ade894eabd2c384d P 542b409cf89a4acf81ec0f700653ed36: Deleting log segment in path: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397728536-29854-0/minicluster-data/ts-0-root/wals/609b6737a2ab4a77ade894eabd2c384d/wal-000000010 (ops 46-50)
I20260812 06:16:45.167814 30197 log.cc:1079] T 609b6737a2ab4a77ade894eabd2c384d P 542b409cf89a4acf81ec0f700653ed36: Deleting log segment in path: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397728536-29854-0/minicluster-data/ts-0-root/wals/609b6737a2ab4a77ade894eabd2c384d/wal-000000011 (ops 51-54)
I20260812 06:16:45.167837 30197 log.cc:1079] T 609b6737a2ab4a77ade894eabd2c384d P 542b409cf89a4acf81ec0f700653ed36: Deleting log segment in path: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397728536-29854-0/minicluster-data/ts-0-root/wals/609b6737a2ab4a77ade894eabd2c384d/wal-000000012 (ops 55-59)
I20260812 06:16:45.167872 30197 log.cc:1079] T 609b6737a2ab4a77ade894eabd2c384d P 542b409cf89a4acf81ec0f700653ed36: Deleting log segment in path: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397728536-29854-0/minicluster-data/ts-0-root/wals/609b6737a2ab4a77ade894eabd2c384d/wal-000000013 (ops 60-64)
I20260812 06:16:45.167915 30197 log.cc:1079] T 609b6737a2ab4a77ade894eabd2c384d P 542b409cf89a4acf81ec0f700653ed36: Deleting log segment in path: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397728536-29854-0/minicluster-data/ts-0-root/wals/609b6737a2ab4a77ade894eabd2c384d/wal-000000014 (ops 65-69)
I20260812 06:16:45.191548 30197 maintenance_manager.cc:643] P 542b409cf89a4acf81ec0f700653ed36: LogGCOp(609b6737a2ab4a77ade894eabd2c384d) complete. Timing: real 0.024s	user 0.000s	sys 0.021s Metrics: {}
I20260812 06:16:45.191972 30271 maintenance_manager.cc:419] P 542b409cf89a4acf81ec0f700653ed36: Scheduling FlushDeltaMemStoresOp(609b6737a2ab4a77ade894eabd2c384d): perf score=2.188937
I20260812 06:16:45.207279 30197 maintenance_manager.cc:643] P 542b409cf89a4acf81ec0f700653ed36: FlushDeltaMemStoresOp(609b6737a2ab4a77ade894eabd2c384d) complete. Timing: real 0.015s	user 0.008s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5531,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:45.208014 30271 maintenance_manager.cc:419] P 542b409cf89a4acf81ec0f700653ed36: Scheduling MajorDeltaCompactionOp(609b6737a2ab4a77ade894eabd2c384d): perf score=1.000000
I20260812 06:16:45.546526 30197 maintenance_manager.cc:643] P 542b409cf89a4acf81ec0f700653ed36: MajorDeltaCompactionOp(609b6737a2ab4a77ade894eabd2c384d) complete. Timing: real 0.338s	user 0.118s	sys 0.112s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877327,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":651,"lbm_read_time_us":12330,"lbm_reads_lt_1ms":670,"lbm_write_time_us":61932,"lbm_writes_1-10_ms":1,"lbm_writes_10-100_ms":1,"lbm_writes_lt_1ms":641,"mutex_wait_us":57,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1152,"thread_start_us":109,"threads_started":1,"update_count":3000}
I20260812 06:16:45.547775 30271 maintenance_manager.cc:419] P 542b409cf89a4acf81ec0f700653ed36: Scheduling FlushDeltaMemStoresOp(609b6737a2ab4a77ade894eabd2c384d): perf score=26.993625
I20260812 06:16:45.641203 30197 maintenance_manager.cc:643] P 542b409cf89a4acf81ec0f700653ed36: FlushDeltaMemStoresOp(609b6737a2ab4a77ade894eabd2c384d) complete. Timing: real 0.093s	user 0.057s	sys 0.020s Metrics: {"bytes_written":29127379,"delete_count":0,"lbm_write_time_us":35539,"lbm_writes_lt_1ms":713,"reinsert_count":0,"update_count":3550}
I20260812 06:16:45.641791 30271 maintenance_manager.cc:419] P 542b409cf89a4acf81ec0f700653ed36: Scheduling FlushDeltaMemStoresOp(609b6737a2ab4a77ade894eabd2c384d): perf score=6.157687
I20260812 06:16:45.749255 30197 maintenance_manager.cc:643] P 542b409cf89a4acf81ec0f700653ed36: FlushDeltaMemStoresOp(609b6737a2ab4a77ade894eabd2c384d) complete. Timing: real 0.107s	user 0.016s	sys 0.008s Metrics: {"bytes_written":7794836,"delete_count":0,"lbm_write_time_us":9560,"lbm_writes_lt_1ms":193,"reinsert_count":0,"update_count":950}
I20260812 06:16:45.749939 30271 maintenance_manager.cc:419] P 542b409cf89a4acf81ec0f700653ed36: Scheduling FlushDeltaMemStoresOp(609b6737a2ab4a77ade894eabd2c384d): perf score=7.149875
I20260812 06:16:45.847016 30197 maintenance_manager.cc:643] P 542b409cf89a4acf81ec0f700653ed36: FlushDeltaMemStoresOp(609b6737a2ab4a77ade894eabd2c384d) complete. Timing: real 0.097s	user 0.006s	sys 0.016s Metrics: {"bytes_written":8738396,"delete_count":0,"lbm_write_time_us":10145,"lbm_writes_lt_1ms":216,"reinsert_count":0,"update_count":1065}
I20260812 06:16:45.847690 30271 maintenance_manager.cc:419] P 542b409cf89a4acf81ec0f700653ed36: Scheduling FlushDeltaMemStoresOp(609b6737a2ab4a77ade894eabd2c384d): perf score=10.126437
I20260812 06:16:45.945406 30197 maintenance_manager.cc:643] P 542b409cf89a4acf81ec0f700653ed36: FlushDeltaMemStoresOp(609b6737a2ab4a77ade894eabd2c384d) complete. Timing: real 0.098s	user 0.029s	sys 0.007s Metrics: {"bytes_written":11610087,"delete_count":0,"lbm_write_time_us":15688,"lbm_writes_lt_1ms":286,"reinsert_count":0,"update_count":1415}
I20260812 06:16:45.945977 30271 maintenance_manager.cc:419] P 542b409cf89a4acf81ec0f700653ed36: Scheduling FlushDeltaMemStoresOp(609b6737a2ab4a77ade894eabd2c384d): perf score=7.149875
I20260812 06:16:46.046002 30197 maintenance_manager.cc:643] P 542b409cf89a4acf81ec0f700653ed36: FlushDeltaMemStoresOp(609b6737a2ab4a77ade894eabd2c384d) complete. Timing: real 0.100s	user 0.010s	sys 0.008s Metrics: {"bytes_written":8369178,"delete_count":0,"lbm_write_time_us":7842,"lbm_writes_lt_1ms":207,"reinsert_count":0,"update_count":1020}
I20260812 06:16:46.046547 30271 maintenance_manager.cc:419] P 542b409cf89a4acf81ec0f700653ed36: Scheduling FlushDeltaMemStoresOp(609b6737a2ab4a77ade894eabd2c384d): perf score=6.157687
I20260812 06:16:46.148020 30197 maintenance_manager.cc:643] P 542b409cf89a4acf81ec0f700653ed36: FlushDeltaMemStoresOp(609b6737a2ab4a77ade894eabd2c384d) complete. Timing: real 0.101s	user 0.017s	sys 0.004s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":9212,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:16:46.148792 30271 maintenance_manager.cc:419] P 542b409cf89a4acf81ec0f700653ed36: Scheduling FlushDeltaMemStoresOp(609b6737a2ab4a77ade894eabd2c384d): perf score=6.157687
I20260812 06:16:46.252934 30197 maintenance_manager.cc:643] P 542b409cf89a4acf81ec0f700653ed36: FlushDeltaMemStoresOp(609b6737a2ab4a77ade894eabd2c384d) complete. Timing: real 0.104s	user 0.015s	sys 0.012s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":11751,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:16:46.253829 30271 maintenance_manager.cc:419] P 542b409cf89a4acf81ec0f700653ed36: Scheduling FlushDeltaMemStoresOp(609b6737a2ab4a77ade894eabd2c384d): perf score=7.149875
I20260812 06:16:46.358469 30197 maintenance_manager.cc:643] P 542b409cf89a4acf81ec0f700653ed36: FlushDeltaMemStoresOp(609b6737a2ab4a77ade894eabd2c384d) complete. Timing: real 0.104s	user 0.011s	sys 0.008s Metrics: {"bytes_written":8615322,"delete_count":0,"lbm_write_time_us":8245,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:16:46.359232 30271 maintenance_manager.cc:419] P 542b409cf89a4acf81ec0f700653ed36: Scheduling FlushDeltaMemStoresOp(609b6737a2ab4a77ade894eabd2c384d): perf score=10.126437
I20260812 06:16:46.462891 30197 maintenance_manager.cc:643] P 542b409cf89a4acf81ec0f700653ed36: FlushDeltaMemStoresOp(609b6737a2ab4a77ade894eabd2c384d) complete. Timing: real 0.103s	user 0.022s	sys 0.019s Metrics: {"bytes_written":11897250,"delete_count":0,"lbm_write_time_us":16637,"lbm_writes_lt_1ms":293,"reinsert_count":0,"update_count":1450}
I20260812 06:16:46.463627 30271 maintenance_manager.cc:419] P 542b409cf89a4acf81ec0f700653ed36: Scheduling FlushDeltaMemStoresOp(609b6737a2ab4a77ade894eabd2c384d): perf score=6.157687
I20260812 06:16:46.558183 30197 maintenance_manager.cc:643] P 542b409cf89a4acf81ec0f700653ed36: FlushDeltaMemStoresOp(609b6737a2ab4a77ade894eabd2c384d) complete. Timing: real 0.094s	user 0.018s	sys 0.004s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":9197,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:16:46.559092 30271 maintenance_manager.cc:419] P 542b409cf89a4acf81ec0f700653ed36: Scheduling FlushDeltaMemStoresOp(609b6737a2ab4a77ade894eabd2c384d): perf score=6.157687
I20260812 06:16:46.662335 30197 maintenance_manager.cc:643] P 542b409cf89a4acf81ec0f700653ed36: FlushDeltaMemStoresOp(609b6737a2ab4a77ade894eabd2c384d) complete. Timing: real 0.103s	user 0.019s	sys 0.012s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":12897,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:16:46.663434 30271 maintenance_manager.cc:419] P 542b409cf89a4acf81ec0f700653ed36: Scheduling FlushDeltaMemStoresOp(609b6737a2ab4a77ade894eabd2c384d): perf score=6.157687
I20260812 06:16:46.757192 30197 maintenance_manager.cc:643] P 542b409cf89a4acf81ec0f700653ed36: FlushDeltaMemStoresOp(609b6737a2ab4a77ade894eabd2c384d) complete. Timing: real 0.093s	user 0.023s	sys 0.011s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":13352,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:16:46.757886 30271 maintenance_manager.cc:419] P 542b409cf89a4acf81ec0f700653ed36: Scheduling FlushDeltaMemStoresOp(609b6737a2ab4a77ade894eabd2c384d): perf score=6.157687
I20260812 06:16:46.861642 30197 maintenance_manager.cc:643] P 542b409cf89a4acf81ec0f700653ed36: FlushDeltaMemStoresOp(609b6737a2ab4a77ade894eabd2c384d) complete. Timing: real 0.104s	user 0.023s	sys 0.008s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":13514,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:16:46.862494 30271 maintenance_manager.cc:419] P 542b409cf89a4acf81ec0f700653ed36: Scheduling FlushDeltaMemStoresOp(609b6737a2ab4a77ade894eabd2c384d): perf score=6.157687
I20260812 06:16:46.968182 30197 maintenance_manager.cc:643] P 542b409cf89a4acf81ec0f700653ed36: FlushDeltaMemStoresOp(609b6737a2ab4a77ade894eabd2c384d) complete. Timing: real 0.105s	user 0.025s	sys 0.010s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":14837,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:16:46.968940 30271 maintenance_manager.cc:419] P 542b409cf89a4acf81ec0f700653ed36: Scheduling FlushDeltaMemStoresOp(609b6737a2ab4a77ade894eabd2c384d): perf score=7.149875
I20260812 06:16:47.068631 30197 maintenance_manager.cc:643] P 542b409cf89a4acf81ec0f700653ed36: FlushDeltaMemStoresOp(609b6737a2ab4a77ade894eabd2c384d) complete. Timing: real 0.099s	user 0.027s	sys 0.009s Metrics: {"bytes_written":8615323,"delete_count":0,"lbm_write_time_us":15582,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:16:47.069500 30271 maintenance_manager.cc:419] P 542b409cf89a4acf81ec0f700653ed36: Scheduling FlushDeltaMemStoresOp(609b6737a2ab4a77ade894eabd2c384d): perf score=3.181125
I20260812 06:16:47.172348 30197 maintenance_manager.cc:643] P 542b409cf89a4acf81ec0f700653ed36: FlushDeltaMemStoresOp(609b6737a2ab4a77ade894eabd2c384d) complete. Timing: real 0.103s	user 0.016s	sys 0.000s Metrics: {"bytes_written":4471881,"delete_count":0,"lbm_write_time_us":6719,"lbm_writes_lt_1ms":112,"reinsert_count":0,"update_count":545}
I20260812 06:16:47.173440 30271 maintenance_manager.cc:419] P 542b409cf89a4acf81ec0f700653ed36: Scheduling FlushDeltaMemStoresOp(609b6737a2ab4a77ade894eabd2c384d): perf score=9.134250
I20260812 06:16:47.279019 30197 maintenance_manager.cc:643] P 542b409cf89a4acf81ec0f700653ed36: FlushDeltaMemStoresOp(609b6737a2ab4a77ade894eabd2c384d) complete. Timing: real 0.105s	user 0.016s	sys 0.013s Metrics: {"bytes_written":11487016,"delete_count":0,"lbm_write_time_us":12456,"lbm_writes_lt_1ms":283,"reinsert_count":0,"update_count":1400}
I20260812 06:16:47.279839 30271 maintenance_manager.cc:419] P 542b409cf89a4acf81ec0f700653ed36: Scheduling FlushDeltaMemStoresOp(609b6737a2ab4a77ade894eabd2c384d): perf score=6.157687
I20260812 06:16:47.383129 30197 maintenance_manager.cc:643] P 542b409cf89a4acf81ec0f700653ed36: FlushDeltaMemStoresOp(609b6737a2ab4a77ade894eabd2c384d) complete. Timing: real 0.103s	user 0.013s	sys 0.008s Metrics: {"bytes_written":8246106,"delete_count":0,"lbm_write_time_us":8986,"lbm_writes_lt_1ms":204,"reinsert_count":0,"update_count":1005}
I20260812 06:16:47.383742 30271 maintenance_manager.cc:419] P 542b409cf89a4acf81ec0f700653ed36: Scheduling FlushDeltaMemStoresOp(609b6737a2ab4a77ade894eabd2c384d): perf score=8.142062
I20260812 06:16:47.479698 30197 maintenance_manager.cc:643] P 542b409cf89a4acf81ec0f700653ed36: FlushDeltaMemStoresOp(609b6737a2ab4a77ade894eabd2c384d) complete. Timing: real 0.096s	user 0.020s	sys 0.005s Metrics: {"bytes_written":10133212,"delete_count":0,"lbm_write_time_us":11399,"lbm_writes_lt_1ms":250,"reinsert_count":0,"update_count":1235}
I20260812 06:16:47.480289 30271 maintenance_manager.cc:419] P 542b409cf89a4acf81ec0f700653ed36: Scheduling FlushDeltaMemStoresOp(609b6737a2ab4a77ade894eabd2c384d): perf score=9.134250
I20260812 06:16:47.582522 30197 maintenance_manager.cc:643] P 542b409cf89a4acf81ec0f700653ed36: FlushDeltaMemStoresOp(609b6737a2ab4a77ade894eabd2c384d) complete. Timing: real 0.102s	user 0.026s	sys 0.001s Metrics: {"bytes_written":10379356,"delete_count":0,"lbm_write_time_us":11413,"lbm_writes_lt_1ms":256,"reinsert_count":0,"update_count":1265}
I20260812 06:16:47.583382 30271 maintenance_manager.cc:419] P 542b409cf89a4acf81ec0f700653ed36: Scheduling FlushDeltaMemStoresOp(609b6737a2ab4a77ade894eabd2c384d): perf score=6.157687
I20260812 06:16:47.676406 30197 maintenance_manager.cc:643] P 542b409cf89a4acf81ec0f700653ed36: FlushDeltaMemStoresOp(609b6737a2ab4a77ade894eabd2c384d) complete. Timing: real 0.093s	user 0.020s	sys 0.003s Metrics: {"bytes_written":8205080,"delete_count":0,"lbm_write_time_us":9950,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:16:47.678704 30271 maintenance_manager.cc:419] P 542b409cf89a4acf81ec0f700653ed36: Scheduling FlushDeltaMemStoresOp(609b6737a2ab4a77ade894eabd2c384d): perf score=6.157687
I20260812 06:16:47.776927 30197 maintenance_manager.cc:643] P 542b409cf89a4acf81ec0f700653ed36: FlushDeltaMemStoresOp(609b6737a2ab4a77ade894eabd2c384d) complete. Timing: real 0.098s	user 0.004s	sys 0.022s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":10926,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:16:47.777868 30271 maintenance_manager.cc:419] P 542b409cf89a4acf81ec0f700653ed36: Scheduling FlushDeltaMemStoresOp(609b6737a2ab4a77ade894eabd2c384d): perf score=6.157687
I20260812 06:16:47.873905 30197 maintenance_manager.cc:643] P 542b409cf89a4acf81ec0f700653ed36: FlushDeltaMemStoresOp(609b6737a2ab4a77ade894eabd2c384d) complete. Timing: real 0.096s	user 0.019s	sys 0.001s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":8380,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:16:47.874606 30271 maintenance_manager.cc:419] P 542b409cf89a4acf81ec0f700653ed36: Scheduling FlushDeltaMemStoresOp(609b6737a2ab4a77ade894eabd2c384d): perf score=10.126437
I20260812 06:16:47.980048 30197 maintenance_manager.cc:643] P 542b409cf89a4acf81ec0f700653ed36: FlushDeltaMemStoresOp(609b6737a2ab4a77ade894eabd2c384d) complete. Timing: real 0.105s	user 0.030s	sys 0.003s Metrics: {"bytes_written":11692131,"delete_count":0,"lbm_write_time_us":12643,"lbm_writes_lt_1ms":288,"reinsert_count":0,"update_count":1425}
I20260812 06:16:47.980749 30271 maintenance_manager.cc:419] P 542b409cf89a4acf81ec0f700653ed36: Scheduling FlushDeltaMemStoresOp(609b6737a2ab4a77ade894eabd2c384d): perf score=7.149875
I20260812 06:16:48.073650 30197 maintenance_manager.cc:643] P 542b409cf89a4acf81ec0f700653ed36: FlushDeltaMemStoresOp(609b6737a2ab4a77ade894eabd2c384d) complete. Timing: real 0.093s	user 0.019s	sys 0.008s Metrics: {"bytes_written":8820446,"delete_count":0,"lbm_write_time_us":11457,"lbm_writes_lt_1ms":218,"reinsert_count":0,"update_count":1075}
I20260812 06:16:48.074249 30271 maintenance_manager.cc:419] P 542b409cf89a4acf81ec0f700653ed36: Scheduling FlushDeltaMemStoresOp(609b6737a2ab4a77ade894eabd2c384d): perf score=6.157687
I20260812 06:16:48.111802 30197 maintenance_manager.cc:643] P 542b409cf89a4acf81ec0f700653ed36: FlushDeltaMemStoresOp(609b6737a2ab4a77ade894eabd2c384d) complete. Timing: real 0.037s	user 0.010s	sys 0.012s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":10808,"lbm_writes_lt_1ms":203,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":1000}
I20260812 06:16:48.112388 30271 maintenance_manager.cc:419] P 542b409cf89a4acf81ec0f700653ed36: Scheduling FlushDeltaMemStoresOp(609b6737a2ab4a77ade894eabd2c384d): perf score=2.188937
I20260812 06:16:48.125411 30197 maintenance_manager.cc:643] P 542b409cf89a4acf81ec0f700653ed36: FlushDeltaMemStoresOp(609b6737a2ab4a77ade894eabd2c384d) complete. Timing: real 0.013s	user 0.009s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5323,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:48.125928 30271 maintenance_manager.cc:419] P 542b409cf89a4acf81ec0f700653ed36: Scheduling FlushMRSOp(609b6737a2ab4a77ade894eabd2c384d): perf score=1.195565
I20260812 06:16:48.164369 30197 maintenance_manager.cc:643] P 542b409cf89a4acf81ec0f700653ed36: FlushMRSOp(609b6737a2ab4a77ade894eabd2c384d) complete. Timing: real 0.038s	user 0.032s	sys 0.004s Metrics: {"bytes_written":2586837,"cfile_init":1,"dirs.queue_time_us":251,"dirs.run_cpu_time_us":266,"dirs.run_wall_time_us":1572,"drs_written":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4,"lbm_write_time_us":3606,"lbm_writes_lt_1ms":44,"peak_mem_usage":0,"rows_written":63,"thread_start_us":102,"threads_started":1}
I20260812 06:16:48.165302 30271 maintenance_manager.cc:419] P 542b409cf89a4acf81ec0f700653ed36: Scheduling LogGCOp(609b6737a2ab4a77ade894eabd2c384d): free 261892143 bytes of WAL
I20260812 06:16:48.165591 30197 log_reader.cc:385] T 609b6737a2ab4a77ade894eabd2c384d: removed 26 log segments from log reader
I20260812 06:16:48.165644 30197 log.cc:1079] T 609b6737a2ab4a77ade894eabd2c384d P 542b409cf89a4acf81ec0f700653ed36: Deleting log segment in path: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397728536-29854-0/minicluster-data/ts-0-root/wals/609b6737a2ab4a77ade894eabd2c384d/wal-000000015 (ops 70-74)
I20260812 06:16:48.165683 30197 log.cc:1079] T 609b6737a2ab4a77ade894eabd2c384d P 542b409cf89a4acf81ec0f700653ed36: Deleting log segment in path: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397728536-29854-0/minicluster-data/ts-0-root/wals/609b6737a2ab4a77ade894eabd2c384d/wal-000000016 (ops 75-79)
I20260812 06:16:48.165711 30197 log.cc:1079] T 609b6737a2ab4a77ade894eabd2c384d P 542b409cf89a4acf81ec0f700653ed36: Deleting log segment in path: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397728536-29854-0/minicluster-data/ts-0-root/wals/609b6737a2ab4a77ade894eabd2c384d/wal-000000017 (ops 80-84)
I20260812 06:16:48.165736 30197 log.cc:1079] T 609b6737a2ab4a77ade894eabd2c384d P 542b409cf89a4acf81ec0f700653ed36: Deleting log segment in path: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397728536-29854-0/minicluster-data/ts-0-root/wals/609b6737a2ab4a77ade894eabd2c384d/wal-000000018 (ops 85-89)
I20260812 06:16:48.165764 30197 log.cc:1079] T 609b6737a2ab4a77ade894eabd2c384d P 542b409cf89a4acf81ec0f700653ed36: Deleting log segment in path: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397728536-29854-0/minicluster-data/ts-0-root/wals/609b6737a2ab4a77ade894eabd2c384d/wal-000000019 (ops 90-94)
I20260812 06:16:48.165786 30197 log.cc:1079] T 609b6737a2ab4a77ade894eabd2c384d P 542b409cf89a4acf81ec0f700653ed36: Deleting log segment in path: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397728536-29854-0/minicluster-data/ts-0-root/wals/609b6737a2ab4a77ade894eabd2c384d/wal-000000020 (ops 95-98)
I20260812 06:16:48.165808 30197 log.cc:1079] T 609b6737a2ab4a77ade894eabd2c384d P 542b409cf89a4acf81ec0f700653ed36: Deleting log segment in path: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397728536-29854-0/minicluster-data/ts-0-root/wals/609b6737a2ab4a77ade894eabd2c384d/wal-000000021 (ops 99-103)
I20260812 06:16:48.165845 30197 log.cc:1079] T 609b6737a2ab4a77ade894eabd2c384d P 542b409cf89a4acf81ec0f700653ed36: Deleting log segment in path: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397728536-29854-0/minicluster-data/ts-0-root/wals/609b6737a2ab4a77ade894eabd2c384d/wal-000000022 (ops 104-108)
I20260812 06:16:48.165872 30197 log.cc:1079] T 609b6737a2ab4a77ade894eabd2c384d P 542b409cf89a4acf81ec0f700653ed36: Deleting log segment in path: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397728536-29854-0/minicluster-data/ts-0-root/wals/609b6737a2ab4a77ade894eabd2c384d/wal-000000023 (ops 109-112)
I20260812 06:16:48.165903 30197 log.cc:1079] T 609b6737a2ab4a77ade894eabd2c384d P 542b409cf89a4acf81ec0f700653ed36: Deleting log segment in path: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397728536-29854-0/minicluster-data/ts-0-root/wals/609b6737a2ab4a77ade894eabd2c384d/wal-000000024 (ops 113-117)
I20260812 06:16:48.165933 30197 log.cc:1079] T 609b6737a2ab4a77ade894eabd2c384d P 542b409cf89a4acf81ec0f700653ed36: Deleting log segment in path: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397728536-29854-0/minicluster-data/ts-0-root/wals/609b6737a2ab4a77ade894eabd2c384d/wal-000000025 (ops 118-122)
I20260812 06:16:48.165963 30197 log.cc:1079] T 609b6737a2ab4a77ade894eabd2c384d P 542b409cf89a4acf81ec0f700653ed36: Deleting log segment in path: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397728536-29854-0/minicluster-data/ts-0-root/wals/609b6737a2ab4a77ade894eabd2c384d/wal-000000026 (ops 123-127)
I20260812 06:16:48.165992 30197 log.cc:1079] T 609b6737a2ab4a77ade894eabd2c384d P 542b409cf89a4acf81ec0f700653ed36: Deleting log segment in path: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397728536-29854-0/minicluster-data/ts-0-root/wals/609b6737a2ab4a77ade894eabd2c384d/wal-000000027 (ops 128-132)
I20260812 06:16:48.166023 30197 log.cc:1079] T 609b6737a2ab4a77ade894eabd2c384d P 542b409cf89a4acf81ec0f700653ed36: Deleting log segment in path: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397728536-29854-0/minicluster-data/ts-0-root/wals/609b6737a2ab4a77ade894eabd2c384d/wal-000000028 (ops 133-136)
I20260812 06:16:48.166059 30197 log.cc:1079] T 609b6737a2ab4a77ade894eabd2c384d P 542b409cf89a4acf81ec0f700653ed36: Deleting log segment in path: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397728536-29854-0/minicluster-data/ts-0-root/wals/609b6737a2ab4a77ade894eabd2c384d/wal-000000029 (ops 137-141)
I20260812 06:16:48.166092 30197 log.cc:1079] T 609b6737a2ab4a77ade894eabd2c384d P 542b409cf89a4acf81ec0f700653ed36: Deleting log segment in path: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397728536-29854-0/minicluster-data/ts-0-root/wals/609b6737a2ab4a77ade894eabd2c384d/wal-000000030 (ops 142-146)
I20260812 06:16:48.166123 30197 log.cc:1079] T 609b6737a2ab4a77ade894eabd2c384d P 542b409cf89a4acf81ec0f700653ed36: Deleting log segment in path: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397728536-29854-0/minicluster-data/ts-0-root/wals/609b6737a2ab4a77ade894eabd2c384d/wal-000000031 (ops 147-151)
I20260812 06:16:48.166145 30197 log.cc:1079] T 609b6737a2ab4a77ade894eabd2c384d P 542b409cf89a4acf81ec0f700653ed36: Deleting log segment in path: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397728536-29854-0/minicluster-data/ts-0-root/wals/609b6737a2ab4a77ade894eabd2c384d/wal-000000032 (ops 152-156)
I20260812 06:16:48.166174 30197 log.cc:1079] T 609b6737a2ab4a77ade894eabd2c384d P 542b409cf89a4acf81ec0f700653ed36: Deleting log segment in path: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397728536-29854-0/minicluster-data/ts-0-root/wals/609b6737a2ab4a77ade894eabd2c384d/wal-000000033 (ops 157-161)
I20260812 06:16:48.166209 30197 log.cc:1079] T 609b6737a2ab4a77ade894eabd2c384d P 542b409cf89a4acf81ec0f700653ed36: Deleting log segment in path: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397728536-29854-0/minicluster-data/ts-0-root/wals/609b6737a2ab4a77ade894eabd2c384d/wal-000000034 (ops 162-166)
I20260812 06:16:48.166242 30197 log.cc:1079] T 609b6737a2ab4a77ade894eabd2c384d P 542b409cf89a4acf81ec0f700653ed36: Deleting log segment in path: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397728536-29854-0/minicluster-data/ts-0-root/wals/609b6737a2ab4a77ade894eabd2c384d/wal-000000035 (ops 167-171)
I20260812 06:16:48.166271 30197 log.cc:1079] T 609b6737a2ab4a77ade894eabd2c384d P 542b409cf89a4acf81ec0f700653ed36: Deleting log segment in path: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397728536-29854-0/minicluster-data/ts-0-root/wals/609b6737a2ab4a77ade894eabd2c384d/wal-000000036 (ops 172-176)
I20260812 06:16:48.166301 30197 log.cc:1079] T 609b6737a2ab4a77ade894eabd2c384d P 542b409cf89a4acf81ec0f700653ed36: Deleting log segment in path: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397728536-29854-0/minicluster-data/ts-0-root/wals/609b6737a2ab4a77ade894eabd2c384d/wal-000000037 (ops 177-180)
I20260812 06:16:48.166330 30197 log.cc:1079] T 609b6737a2ab4a77ade894eabd2c384d P 542b409cf89a4acf81ec0f700653ed36: Deleting log segment in path: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397728536-29854-0/minicluster-data/ts-0-root/wals/609b6737a2ab4a77ade894eabd2c384d/wal-000000038 (ops 181-185)
I20260812 06:16:48.166363 30197 log.cc:1079] T 609b6737a2ab4a77ade894eabd2c384d P 542b409cf89a4acf81ec0f700653ed36: Deleting log segment in path: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397728536-29854-0/minicluster-data/ts-0-root/wals/609b6737a2ab4a77ade894eabd2c384d/wal-000000039 (ops 186-190)
I20260812 06:16:48.166397 30197 log.cc:1079] T 609b6737a2ab4a77ade894eabd2c384d P 542b409cf89a4acf81ec0f700653ed36: Deleting log segment in path: /tmp/dist-test-task7WPJfK/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515397728536-29854-0/minicluster-data/ts-0-root/wals/609b6737a2ab4a77ade894eabd2c384d/wal-000000040 (ops 191-195)
I20260812 06:16:48.225580 30197 maintenance_manager.cc:643] P 542b409cf89a4acf81ec0f700653ed36: LogGCOp(609b6737a2ab4a77ade894eabd2c384d) complete. Timing: real 0.060s	user 0.003s	sys 0.056s Metrics: {}
I20260812 06:16:48.226052 30271 maintenance_manager.cc:419] P 542b409cf89a4acf81ec0f700653ed36: Scheduling FlushDeltaMemStoresOp(609b6737a2ab4a77ade894eabd2c384d): perf score=6.157687
I20260812 06:16:48.260778 30197 maintenance_manager.cc:643] P 542b409cf89a4acf81ec0f700653ed36: FlushDeltaMemStoresOp(609b6737a2ab4a77ade894eabd2c384d) complete. Timing: real 0.035s	user 0.010s	sys 0.016s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":11869,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:16:48.261281 30271 maintenance_manager.cc:419] P 542b409cf89a4acf81ec0f700653ed36: Scheduling UndoDeltaBlockGCOp(609b6737a2ab4a77ade894eabd2c384d): 844 bytes on disk
I20260812 06:16:48.261729 30197 maintenance_manager.cc:643] P 542b409cf89a4acf81ec0f700653ed36: UndoDeltaBlockGCOp(609b6737a2ab4a77ade894eabd2c384d) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":71,"lbm_reads_lt_1ms":4}
I20260812 06:16:48.262271 30271 maintenance_manager.cc:419] P 542b409cf89a4acf81ec0f700653ed36: Scheduling FlushDeltaMemStoresOp(609b6737a2ab4a77ade894eabd2c384d): perf score=2.188937
I20260812 06:16:48.277793 30197 maintenance_manager.cc:643] P 542b409cf89a4acf81ec0f700653ed36: FlushDeltaMemStoresOp(609b6737a2ab4a77ade894eabd2c384d) complete. Timing: real 0.015s	user 0.013s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5949,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:48.278362 30271 maintenance_manager.cc:419] P 542b409cf89a4acf81ec0f700653ed36: Scheduling MajorDeltaCompactionOp(609b6737a2ab4a77ade894eabd2c384d): perf score=1.000000
I20260812 06:16:48.312773 29854 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.750s	user 1.790s	sys 0.124s
I20260812 06:16:50.072085 30209 rpcz_store.cc:275] Call kudu.tserver.TabletServerService.Scan from 127.0.0.1:41334 (request call id 202) took 1758 ms. Trace:
I20260812 06:16:50.072264 30209 rpcz_store.cc:276] 0812 06:16:48.313918 (+     0us) service_pool.cc:167] Inserting onto call queue
0812 06:16:48.313996 (+    78us) service_pool.cc:224] Handling call
0812 06:16:48.314231 (+   235us) tablet_service.cc:2890] Created scanner a164a90f94e84333a48981511d5207f9 for tablet 609b6737a2ab4a77ade894eabd2c384d, query id is b4264782a32843f99db78acf97386693
0812 06:16:48.314661 (+   430us) tablet_service.cc:3030] Creating iterator
0812 06:16:48.314695 (+    34us) tablet_service.cc:3408] Waiting safe time to advance
0812 06:16:48.314706 (+    11us) tablet_service.cc:3415] Waiting for operations to commit
0812 06:16:48.314726 (+    20us) tablet_service.cc:3431] All operations in snapshot committed. Waited for 19 microseconds
0812 06:16:48.314799 (+    73us) tablet_service.cc:3055] Iterator created
0812 06:16:49.978406 (+1663607us) tablet_service.cc:3077] Iterator init: OK
0812 06:16:49.978477 (+    71us) tablet_service.cc:3120] has_more: true
0812 06:16:49.978559 (+    82us) tablet_service.cc:3137] Continuing scan request
0812 06:16:49.978635 (+    76us) tablet_service.cc:3201] Found scanner a164a90f94e84333a48981511d5207f9 for tablet 609b6737a2ab4a77ade894eabd2c384d, query id is b4264782a32843f99db78acf97386693
0812 06:16:50.072059 (+ 93424us) inbound_call.cc:177] Queueing success response
Metrics: {"cfile_cache_hit":32,"cfile_cache_hit_bytes":88994,"cfile_cache_miss":6531,"cfile_cache_miss_bytes":270833913,"cfile_init":7,"delta_iterators_relevant":36,"lbm_read_time_us":149760,"lbm_reads_1-10_ms":4,"lbm_reads_lt_1ms":6555,"rowset_iterators":2,"scanner_bytes_read":2950785,"spinlock_wait_cycles":92928}
W20260812 06:16:50.075208 29854 scanner-internal.cc:458] Time spent opening tablet: real 1.762s	user 0.001s	sys 0.000s
I20260812 06:16:50.077673 29854 heavy-update-compaction-itest.cc:265] Time spent scanning: real 1.764s	user 0.002s	sys 0.000s
I20260812 06:16:50.078305 29854 tablet_server.cc:179] TabletServer@127.29.39.129:0 shutting down...
I20260812 06:16:52.104101 30197 maintenance_manager.cc:643] P 542b409cf89a4acf81ec0f700653ed36: MajorDeltaCompactionOp(609b6737a2ab4a77ade894eabd2c384d) complete. Timing: real 3.826s	user 1.063s	sys 2.743s Metrics: {"cfile_cache_miss":6559,"cfile_cache_miss_bytes":270922696,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":29,"delta_iterators_relevant":29,"dirs.queue_time_us":1891,"lbm_read_time_us":109888,"lbm_reads_lt_1ms":6595,"lbm_write_time_us":805243,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":6547,"mutex_wait_us":361,"peak_mem_usage":808710220,"reinsert_count":0,"spinlock_wait_cycles":992000,"thread_start_us":711,"threads_started":8,"update_count":32500,"wal-append.queue_time_us":252}
I20260812 06:16:52.104876 29854 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:16:52.105270 29854 tablet_replica.cc:333] T 609b6737a2ab4a77ade894eabd2c384d P 542b409cf89a4acf81ec0f700653ed36: stopping tablet replica
I20260812 06:16:52.105460 29854 raft_consensus.cc:2243] T 609b6737a2ab4a77ade894eabd2c384d P 542b409cf89a4acf81ec0f700653ed36 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:52.105681 29854 raft_consensus.cc:2272] T 609b6737a2ab4a77ade894eabd2c384d P 542b409cf89a4acf81ec0f700653ed36 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:52.119987 29854 tablet_server.cc:196] TabletServer@127.29.39.129:0 shutdown complete.
I20260812 06:16:53.138394 29854 master.cc:562] Master@127.29.39.190:41601 shutting down...
I20260812 06:16:53.142665 29854 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 1d6281ea68bb45ca98891b97f29ccc2e [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:53.142890 29854 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 1d6281ea68bb45ca98891b97f29ccc2e [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:53.142954 29854 tablet_replica.cc:333] T 00000000000000000000000000000000 P 1d6281ea68bb45ca98891b97f29ccc2e: stopping tablet replica
I20260812 06:16:53.156345 29854 master.cc:584] Master@127.29.39.190:41601 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (9887 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (15506 ms total)

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