[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:20:27.648855 22236 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.21.183.62:40131
I20260812 06:20:27.649932 22236 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:20:27.650610 22236 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:27.658351 22242 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:27.658411 22236 server_base.cc:1061] running on GCE node
W20260812 06:20:27.658279 22244 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:27.658602 22241 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:27.659106 22236 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:27.659204 22236 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:27.659232 22236 hybrid_clock.cc:648] HybridClock initialized: now 1786515627659230 us; error 0 us; skew 500 ppm
I20260812 06:20:27.661206 22236 webserver.cc:533] Webserver started at http://127.21.183.62:39643/ using document root <none> and password file <none>
I20260812 06:20:27.661772 22236 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:27.661835 22236 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:27.662034 22236 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:27.663765 22236 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515627637820-22236-0/minicluster-data/master-0-root/instance:
uuid: "5f51b69f8d45478b87cfb9c02e8d6f0c"
format_stamp: "Formatted at 2026-08-12 06:20:27 on dist-test-slave-dhph"
I20260812 06:20:27.667738 22236 fs_manager.cc:696] Time spent creating directory manager: real 0.004s	user 0.003s	sys 0.001s
I20260812 06:20:27.670287 22251 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:27.671648 22236 fs_manager.cc:730] Time spent opening block manager: real 0.003s	user 0.002s	sys 0.001s
I20260812 06:20:27.671833 22236 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515627637820-22236-0/minicluster-data/master-0-root
uuid: "5f51b69f8d45478b87cfb9c02e8d6f0c"
format_stamp: "Formatted at 2026-08-12 06:20:27 on dist-test-slave-dhph"
I20260812 06:20:27.671944 22236 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515627637820-22236-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515627637820-22236-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515627637820-22236-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:27.685290 22236 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:27.685971 22236 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:20:27.686120 22236 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:27.695010 22236 rpc_server.cc:307] RPC server started. Bound to: 127.21.183.62:40131
I20260812 06:20:27.695063 22313 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.21.183.62:40131 every 8 connection(s)
I20260812 06:20:27.697628 22314 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:27.704181 22314 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 5f51b69f8d45478b87cfb9c02e8d6f0c: Bootstrap starting.
I20260812 06:20:27.706789 22314 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 5f51b69f8d45478b87cfb9c02e8d6f0c: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:27.708055 22314 log.cc:826] T 00000000000000000000000000000000 P 5f51b69f8d45478b87cfb9c02e8d6f0c: Log is configured to *not* fsync() on all Append() calls
I20260812 06:20:27.710073 22314 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 5f51b69f8d45478b87cfb9c02e8d6f0c: No bootstrap required, opened a new log
I20260812 06:20:27.713325 22314 raft_consensus.cc:359] T 00000000000000000000000000000000 P 5f51b69f8d45478b87cfb9c02e8d6f0c [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5f51b69f8d45478b87cfb9c02e8d6f0c" member_type: VOTER }
I20260812 06:20:27.713526 22314 raft_consensus.cc:385] T 00000000000000000000000000000000 P 5f51b69f8d45478b87cfb9c02e8d6f0c [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:27.713600 22314 raft_consensus.cc:740] T 00000000000000000000000000000000 P 5f51b69f8d45478b87cfb9c02e8d6f0c [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 5f51b69f8d45478b87cfb9c02e8d6f0c, State: Initialized, Role: FOLLOWER
I20260812 06:20:27.714283 22314 consensus_queue.cc:260] T 00000000000000000000000000000000 P 5f51b69f8d45478b87cfb9c02e8d6f0c [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: "5f51b69f8d45478b87cfb9c02e8d6f0c" member_type: VOTER }
I20260812 06:20:27.714435 22314 raft_consensus.cc:399] T 00000000000000000000000000000000 P 5f51b69f8d45478b87cfb9c02e8d6f0c [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:27.714510 22314 raft_consensus.cc:493] T 00000000000000000000000000000000 P 5f51b69f8d45478b87cfb9c02e8d6f0c [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:27.714700 22314 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 5f51b69f8d45478b87cfb9c02e8d6f0c [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:27.715619 22314 raft_consensus.cc:515] T 00000000000000000000000000000000 P 5f51b69f8d45478b87cfb9c02e8d6f0c [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5f51b69f8d45478b87cfb9c02e8d6f0c" member_type: VOTER }
I20260812 06:20:27.716106 22314 leader_election.cc:304] T 00000000000000000000000000000000 P 5f51b69f8d45478b87cfb9c02e8d6f0c [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: 5f51b69f8d45478b87cfb9c02e8d6f0c; no voters: 
I20260812 06:20:27.716504 22314 leader_election.cc:290] T 00000000000000000000000000000000 P 5f51b69f8d45478b87cfb9c02e8d6f0c [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:27.716701 22318 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 5f51b69f8d45478b87cfb9c02e8d6f0c [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:27.717029 22318 raft_consensus.cc:697] T 00000000000000000000000000000000 P 5f51b69f8d45478b87cfb9c02e8d6f0c [term 1 LEADER]: Becoming Leader. State: Replica: 5f51b69f8d45478b87cfb9c02e8d6f0c, State: Running, Role: LEADER
I20260812 06:20:27.717484 22318 consensus_queue.cc:237] T 00000000000000000000000000000000 P 5f51b69f8d45478b87cfb9c02e8d6f0c [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: "5f51b69f8d45478b87cfb9c02e8d6f0c" member_type: VOTER }
I20260812 06:20:27.717600 22314 sys_catalog.cc:565] T 00000000000000000000000000000000 P 5f51b69f8d45478b87cfb9c02e8d6f0c [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:27.719722 22323 sys_catalog.cc:455] T 00000000000000000000000000000000 P 5f51b69f8d45478b87cfb9c02e8d6f0c [sys.catalog]: SysCatalogTable state changed. Reason: New leader 5f51b69f8d45478b87cfb9c02e8d6f0c. Latest consensus state: current_term: 1 leader_uuid: "5f51b69f8d45478b87cfb9c02e8d6f0c" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5f51b69f8d45478b87cfb9c02e8d6f0c" member_type: VOTER } }
I20260812 06:20:27.719766 22322 sys_catalog.cc:455] T 00000000000000000000000000000000 P 5f51b69f8d45478b87cfb9c02e8d6f0c [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "5f51b69f8d45478b87cfb9c02e8d6f0c" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5f51b69f8d45478b87cfb9c02e8d6f0c" member_type: VOTER } }
I20260812 06:20:27.719866 22322 sys_catalog.cc:458] T 00000000000000000000000000000000 P 5f51b69f8d45478b87cfb9c02e8d6f0c [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:27.719866 22323 sys_catalog.cc:458] T 00000000000000000000000000000000 P 5f51b69f8d45478b87cfb9c02e8d6f0c [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:27.720377 22331 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:27.720736 22236 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:27.723192 22331 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:27.728881 22331 catalog_manager.cc:1383] Generated new cluster ID: 1ef2565059e24923af2b26c072a4bd63
I20260812 06:20:27.728991 22331 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:27.754737 22331 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:27.755999 22331 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:27.763492 22331 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 5f51b69f8d45478b87cfb9c02e8d6f0c: Generated new TSK 0
I20260812 06:20:27.764333 22331 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:27.786939 22236 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:27.790529 22346 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:27.790560 22349 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:27.791144 22347 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:27.791251 22236 server_base.cc:1061] running on GCE node
I20260812 06:20:27.791679 22236 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:27.791841 22236 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:27.791877 22236 hybrid_clock.cc:648] HybridClock initialized: now 1786515627791875 us; error 0 us; skew 500 ppm
I20260812 06:20:27.793015 22236 webserver.cc:533] Webserver started at http://127.21.183.1:44811/ using document root <none> and password file <none>
I20260812 06:20:27.793246 22236 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:27.793325 22236 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:27.793426 22236 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:27.794165 22236 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515627637820-22236-0/minicluster-data/ts-0-root/instance:
uuid: "adfa35c5f5ca4e308ebc35ac488dbaa4"
format_stamp: "Formatted at 2026-08-12 06:20:27 on dist-test-slave-dhph"
I20260812 06:20:27.796060 22236 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.000s	sys 0.003s
I20260812 06:20:27.797513 22354 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:27.797809 22236 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:20:27.797998 22236 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515627637820-22236-0/minicluster-data/ts-0-root
uuid: "adfa35c5f5ca4e308ebc35ac488dbaa4"
format_stamp: "Formatted at 2026-08-12 06:20:27 on dist-test-slave-dhph"
I20260812 06:20:27.798146 22236 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515627637820-22236-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515627637820-22236-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515627637820-22236-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:27.803368 22236 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:27.804003 22236 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:27.804620 22236 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:27.805610 22236 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:27.805675 22236 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:27.805758 22236 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:27.805799 22236 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:27.814543 22236 rpc_server.cc:307] RPC server started. Bound to: 127.21.183.1:37355
I20260812 06:20:27.814621 22432 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.21.183.1:37355 every 8 connection(s)
I20260812 06:20:27.833698 22433 heartbeater.cc:344] Connected to a master server at 127.21.183.62:40131
I20260812 06:20:27.834009 22433 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:27.834558 22433 heartbeater.cc:507] Master 127.21.183.62:40131 requested a full tablet report, sending...
I20260812 06:20:27.836251 22270 ts_manager.cc:194] Registered new tserver with Master: adfa35c5f5ca4e308ebc35ac488dbaa4 (127.21.183.1:37355)
I20260812 06:20:27.836362 22236 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.020957457s
I20260812 06:20:27.838001 22270 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:54242
I20260812 06:20:27.847647 22270 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:54252:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:20:27.864331 22388 tablet_service.cc:1511] Processing CreateTablet for tablet d0d3231a4b844f70a7de74c666bedc06 (DEFAULT_TABLE table=heavy-update-compaction-test [id=48e5730ac074401e943a85b1faaa4a14]), partition=
I20260812 06:20:27.864886 22388 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet d0d3231a4b844f70a7de74c666bedc06. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:27.867463 22446 tablet_bootstrap.cc:492] T d0d3231a4b844f70a7de74c666bedc06 P adfa35c5f5ca4e308ebc35ac488dbaa4: Bootstrap starting.
I20260812 06:20:27.868979 22446 tablet_bootstrap.cc:654] T d0d3231a4b844f70a7de74c666bedc06 P adfa35c5f5ca4e308ebc35ac488dbaa4: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:27.870625 22446 tablet_bootstrap.cc:492] T d0d3231a4b844f70a7de74c666bedc06 P adfa35c5f5ca4e308ebc35ac488dbaa4: No bootstrap required, opened a new log
I20260812 06:20:27.870746 22446 ts_tablet_manager.cc:1403] T d0d3231a4b844f70a7de74c666bedc06 P adfa35c5f5ca4e308ebc35ac488dbaa4: Time spent bootstrapping tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:20:27.871338 22446 raft_consensus.cc:359] T d0d3231a4b844f70a7de74c666bedc06 P adfa35c5f5ca4e308ebc35ac488dbaa4 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "adfa35c5f5ca4e308ebc35ac488dbaa4" member_type: VOTER last_known_addr { host: "127.21.183.1" port: 37355 } }
I20260812 06:20:27.871491 22446 raft_consensus.cc:385] T d0d3231a4b844f70a7de74c666bedc06 P adfa35c5f5ca4e308ebc35ac488dbaa4 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:27.871536 22446 raft_consensus.cc:740] T d0d3231a4b844f70a7de74c666bedc06 P adfa35c5f5ca4e308ebc35ac488dbaa4 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: adfa35c5f5ca4e308ebc35ac488dbaa4, State: Initialized, Role: FOLLOWER
I20260812 06:20:27.871728 22446 consensus_queue.cc:260] T d0d3231a4b844f70a7de74c666bedc06 P adfa35c5f5ca4e308ebc35ac488dbaa4 [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: "adfa35c5f5ca4e308ebc35ac488dbaa4" member_type: VOTER last_known_addr { host: "127.21.183.1" port: 37355 } }
I20260812 06:20:27.871850 22446 raft_consensus.cc:399] T d0d3231a4b844f70a7de74c666bedc06 P adfa35c5f5ca4e308ebc35ac488dbaa4 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:27.871946 22446 raft_consensus.cc:493] T d0d3231a4b844f70a7de74c666bedc06 P adfa35c5f5ca4e308ebc35ac488dbaa4 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:27.872022 22446 raft_consensus.cc:3060] T d0d3231a4b844f70a7de74c666bedc06 P adfa35c5f5ca4e308ebc35ac488dbaa4 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:27.873184 22446 raft_consensus.cc:515] T d0d3231a4b844f70a7de74c666bedc06 P adfa35c5f5ca4e308ebc35ac488dbaa4 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "adfa35c5f5ca4e308ebc35ac488dbaa4" member_type: VOTER last_known_addr { host: "127.21.183.1" port: 37355 } }
I20260812 06:20:27.873400 22446 leader_election.cc:304] T d0d3231a4b844f70a7de74c666bedc06 P adfa35c5f5ca4e308ebc35ac488dbaa4 [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: adfa35c5f5ca4e308ebc35ac488dbaa4; no voters: 
I20260812 06:20:27.873647 22446 leader_election.cc:290] T d0d3231a4b844f70a7de74c666bedc06 P adfa35c5f5ca4e308ebc35ac488dbaa4 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:27.873975 22448 raft_consensus.cc:2804] T d0d3231a4b844f70a7de74c666bedc06 P adfa35c5f5ca4e308ebc35ac488dbaa4 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:27.874136 22446 ts_tablet_manager.cc:1434] T d0d3231a4b844f70a7de74c666bedc06 P adfa35c5f5ca4e308ebc35ac488dbaa4: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:20:27.874425 22448 raft_consensus.cc:697] T d0d3231a4b844f70a7de74c666bedc06 P adfa35c5f5ca4e308ebc35ac488dbaa4 [term 1 LEADER]: Becoming Leader. State: Replica: adfa35c5f5ca4e308ebc35ac488dbaa4, State: Running, Role: LEADER
I20260812 06:20:27.874688 22433 heartbeater.cc:499] Master 127.21.183.62:40131 was elected leader, sending a full tablet report...
I20260812 06:20:27.874706 22448 consensus_queue.cc:237] T d0d3231a4b844f70a7de74c666bedc06 P adfa35c5f5ca4e308ebc35ac488dbaa4 [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: "adfa35c5f5ca4e308ebc35ac488dbaa4" member_type: VOTER last_known_addr { host: "127.21.183.1" port: 37355 } }
I20260812 06:20:27.878177 22269 catalog_manager.cc:5719] T d0d3231a4b844f70a7de74c666bedc06 P adfa35c5f5ca4e308ebc35ac488dbaa4 reported cstate change: term changed from 0 to 1, leader changed from <none> to adfa35c5f5ca4e308ebc35ac488dbaa4 (127.21.183.1). New cstate: current_term: 1 leader_uuid: "adfa35c5f5ca4e308ebc35ac488dbaa4" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "adfa35c5f5ca4e308ebc35ac488dbaa4" member_type: VOTER last_known_addr { host: "127.21.183.1" port: 37355 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:27.956950 22236 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.071s	user 0.025s	sys 0.010s
I20260812 06:20:28.065981 22434 maintenance_manager.cc:419] P adfa35c5f5ca4e308ebc35ac488dbaa4: Scheduling FlushMRSOp(d0d3231a4b844f70a7de74c666bedc06): perf score=15.086190
I20260812 06:20:28.215067 22360 maintenance_manager.cc:643] P adfa35c5f5ca4e308ebc35ac488dbaa4: FlushMRSOp(d0d3231a4b844f70a7de74c666bedc06) complete. Timing: real 0.149s	user 0.091s	sys 0.047s Metrics: {"bytes_written":8205078,"cfile_init":1,"compiler_manager_pool.queue_time_us":290,"delete_count":0,"dirs.queue_time_us":67,"dirs.run_cpu_time_us":190,"dirs.run_wall_time_us":928,"drs_written":1,"lbm_read_time_us":113,"lbm_reads_lt_1ms":4,"lbm_write_time_us":33698,"lbm_writes_lt_1ms":557,"peak_mem_usage":0,"reinsert_count":0,"rows_written":103,"thread_start_us":196,"threads_started":1,"update_count":1000}
I20260812 06:20:28.216152 22434 maintenance_manager.cc:419] P adfa35c5f5ca4e308ebc35ac488dbaa4: Scheduling LogGCOp(d0d3231a4b844f70a7de74c666bedc06): free 11976772 bytes of WAL
I20260812 06:20:28.216463 22360 log_reader.cc:385] T d0d3231a4b844f70a7de74c666bedc06: removed 1 log segments from log reader
I20260812 06:20:28.216544 22360 log.cc:1079] T d0d3231a4b844f70a7de74c666bedc06 P adfa35c5f5ca4e308ebc35ac488dbaa4: Deleting log segment in path: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515627637820-22236-0/minicluster-data/ts-0-root/wals/d0d3231a4b844f70a7de74c666bedc06/wal-000000001 (ops 1-6)
I20260812 06:20:28.219537 22360 maintenance_manager.cc:643] P adfa35c5f5ca4e308ebc35ac488dbaa4: LogGCOp(d0d3231a4b844f70a7de74c666bedc06) complete. Timing: real 0.003s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:20:28.219965 22434 maintenance_manager.cc:419] P adfa35c5f5ca4e308ebc35ac488dbaa4: Scheduling FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06): perf score=2.188937
I20260812 06:20:28.239439 22360 maintenance_manager.cc:643] P adfa35c5f5ca4e308ebc35ac488dbaa4: FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06) complete. Timing: real 0.019s	user 0.010s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7048,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:28.240061 22434 maintenance_manager.cc:419] P adfa35c5f5ca4e308ebc35ac488dbaa4: Scheduling MajorDeltaCompactionOp(d0d3231a4b844f70a7de74c666bedc06): perf score=1.000000
I20260812 06:20:28.353179 22360 maintenance_manager.cc:643] P adfa35c5f5ca4e308ebc35ac488dbaa4: MajorDeltaCompactionOp(d0d3231a4b844f70a7de74c666bedc06) complete. Timing: real 0.113s	user 0.087s	sys 0.024s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16528900,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":552,"lbm_read_time_us":7377,"lbm_reads_lt_1ms":368,"lbm_write_time_us":19496,"lbm_writes_lt_1ms":343,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":24704,"thread_start_us":333,"threads_started":5,"update_count":1500}
I20260812 06:20:28.353823 22434 maintenance_manager.cc:419] P adfa35c5f5ca4e308ebc35ac488dbaa4: Scheduling FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06): perf score=7.149875
I20260812 06:20:28.378096 22360 maintenance_manager.cc:643] P adfa35c5f5ca4e308ebc35ac488dbaa4: FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06) complete. Timing: real 0.024s	user 0.014s	sys 0.007s Metrics: {"bytes_written":8615323,"delete_count":0,"lbm_write_time_us":9980,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:20:28.378664 22434 maintenance_manager.cc:419] P adfa35c5f5ca4e308ebc35ac488dbaa4: Scheduling FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06): perf score=2.188937
I20260812 06:20:28.392434 22360 maintenance_manager.cc:643] P adfa35c5f5ca4e308ebc35ac488dbaa4: FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06) complete. Timing: real 0.014s	user 0.011s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4912,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:28.393033 22434 maintenance_manager.cc:419] P adfa35c5f5ca4e308ebc35ac488dbaa4: Scheduling MajorDeltaCompactionOp(d0d3231a4b844f70a7de74c666bedc06): perf score=1.000000
I20260812 06:20:28.494784 22360 maintenance_manager.cc:643] P adfa35c5f5ca4e308ebc35ac488dbaa4: MajorDeltaCompactionOp(d0d3231a4b844f70a7de74c666bedc06) complete. Timing: real 0.102s	user 0.078s	sys 0.023s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16528891,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":226,"lbm_read_time_us":6523,"lbm_reads_lt_1ms":372,"lbm_write_time_us":18159,"lbm_writes_lt_1ms":343,"mutex_wait_us":45,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":10496,"update_count":1500}
I20260812 06:20:28.495553 22434 maintenance_manager.cc:419] P adfa35c5f5ca4e308ebc35ac488dbaa4: Scheduling FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06): perf score=7.149875
I20260812 06:20:28.523080 22360 maintenance_manager.cc:643] P adfa35c5f5ca4e308ebc35ac488dbaa4: FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06) complete. Timing: real 0.027s	user 0.019s	sys 0.008s Metrics: {"bytes_written":8615323,"delete_count":0,"lbm_write_time_us":11711,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:20:28.523557 22434 maintenance_manager.cc:419] P adfa35c5f5ca4e308ebc35ac488dbaa4: Scheduling FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06): perf score=2.188937
I20260812 06:20:28.533372 22360 maintenance_manager.cc:643] P adfa35c5f5ca4e308ebc35ac488dbaa4: FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06) complete. Timing: real 0.010s	user 0.000s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3774,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:28.533980 22434 maintenance_manager.cc:419] P adfa35c5f5ca4e308ebc35ac488dbaa4: Scheduling UndoDeltaBlockGCOp(d0d3231a4b844f70a7de74c666bedc06): 12308958 bytes on disk
I20260812 06:20:28.534832 22360 maintenance_manager.cc:643] P adfa35c5f5ca4e308ebc35ac488dbaa4: UndoDeltaBlockGCOp(d0d3231a4b844f70a7de74c666bedc06) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":117,"lbm_reads_lt_1ms":4}
I20260812 06:20:28.535317 22434 maintenance_manager.cc:419] P adfa35c5f5ca4e308ebc35ac488dbaa4: Scheduling MajorDeltaCompactionOp(d0d3231a4b844f70a7de74c666bedc06): perf score=1.000000
I20260812 06:20:28.657605 22360 maintenance_manager.cc:643] P adfa35c5f5ca4e308ebc35ac488dbaa4: MajorDeltaCompactionOp(d0d3231a4b844f70a7de74c666bedc06) complete. Timing: real 0.122s	user 0.089s	sys 0.033s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16528891,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":223,"lbm_read_time_us":7996,"lbm_reads_lt_1ms":372,"lbm_write_time_us":22828,"lbm_writes_lt_1ms":343,"mutex_wait_us":44,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":23808,"update_count":1500}
I20260812 06:20:28.658347 22434 maintenance_manager.cc:419] P adfa35c5f5ca4e308ebc35ac488dbaa4: Scheduling FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06): perf score=7.149875
I20260812 06:20:28.682428 22360 maintenance_manager.cc:643] P adfa35c5f5ca4e308ebc35ac488dbaa4: FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06) complete. Timing: real 0.024s	user 0.021s	sys 0.000s Metrics: {"bytes_written":8615323,"delete_count":0,"lbm_write_time_us":9900,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:20:28.683142 22434 maintenance_manager.cc:419] P adfa35c5f5ca4e308ebc35ac488dbaa4: Scheduling FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06): perf score=2.188937
I20260812 06:20:28.699373 22360 maintenance_manager.cc:643] P adfa35c5f5ca4e308ebc35ac488dbaa4: FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06) complete. Timing: real 0.016s	user 0.012s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6001,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:28.699942 22434 maintenance_manager.cc:419] P adfa35c5f5ca4e308ebc35ac488dbaa4: Scheduling MajorDeltaCompactionOp(d0d3231a4b844f70a7de74c666bedc06): perf score=1.000000
I20260812 06:20:28.846199 22360 maintenance_manager.cc:643] P adfa35c5f5ca4e308ebc35ac488dbaa4: MajorDeltaCompactionOp(d0d3231a4b844f70a7de74c666bedc06) complete. Timing: real 0.146s	user 0.115s	sys 0.020s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16528891,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":994,"lbm_read_time_us":10081,"lbm_reads_lt_1ms":364,"lbm_write_time_us":25286,"lbm_writes_lt_1ms":343,"mutex_wait_us":265,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":7808,"update_count":1500}
I20260812 06:20:28.846877 22434 maintenance_manager.cc:419] P adfa35c5f5ca4e308ebc35ac488dbaa4: Scheduling FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06): perf score=10.126437
I20260812 06:20:28.899379 22360 maintenance_manager.cc:643] P adfa35c5f5ca4e308ebc35ac488dbaa4: FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06) complete. Timing: real 0.052s	user 0.030s	sys 0.009s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":17961,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:28.899935 22434 maintenance_manager.cc:419] P adfa35c5f5ca4e308ebc35ac488dbaa4: Scheduling FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06): perf score=2.188937
I20260812 06:20:28.912909 22360 maintenance_manager.cc:643] P adfa35c5f5ca4e308ebc35ac488dbaa4: FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06) complete. Timing: real 0.013s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4627,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:28.913511 22434 maintenance_manager.cc:419] P adfa35c5f5ca4e308ebc35ac488dbaa4: Scheduling MajorDeltaCompactionOp(d0d3231a4b844f70a7de74c666bedc06): perf score=1.000000
I20260812 06:20:29.054996 22360 maintenance_manager.cc:643] P adfa35c5f5ca4e308ebc35ac488dbaa4: MajorDeltaCompactionOp(d0d3231a4b844f70a7de74c666bedc06) complete. Timing: real 0.141s	user 0.120s	sys 0.017s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631313,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1530,"lbm_read_time_us":10482,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26588,"lbm_writes_lt_1ms":443,"mutex_wait_us":470,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":13824,"update_count":2000}
I20260812 06:20:29.055876 22434 maintenance_manager.cc:419] P adfa35c5f5ca4e308ebc35ac488dbaa4: Scheduling FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06): perf score=10.126437
I20260812 06:20:29.104301 22360 maintenance_manager.cc:643] P adfa35c5f5ca4e308ebc35ac488dbaa4: FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06) complete. Timing: real 0.048s	user 0.017s	sys 0.028s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":21826,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:20:29.104787 22434 maintenance_manager.cc:419] P adfa35c5f5ca4e308ebc35ac488dbaa4: Scheduling FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06): perf score=2.188937
I20260812 06:20:29.116272 22360 maintenance_manager.cc:643] P adfa35c5f5ca4e308ebc35ac488dbaa4: FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4174,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:29.116832 22434 maintenance_manager.cc:419] P adfa35c5f5ca4e308ebc35ac488dbaa4: Scheduling MajorDeltaCompactionOp(d0d3231a4b844f70a7de74c666bedc06): perf score=1.000000
I20260812 06:20:29.244289 22360 maintenance_manager.cc:643] P adfa35c5f5ca4e308ebc35ac488dbaa4: MajorDeltaCompactionOp(d0d3231a4b844f70a7de74c666bedc06) complete. Timing: real 0.127s	user 0.098s	sys 0.023s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":587,"lbm_read_time_us":9199,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23330,"lbm_writes_lt_1ms":443,"mutex_wait_us":198,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":13056,"update_count":2000}
I20260812 06:20:29.245031 22434 maintenance_manager.cc:419] P adfa35c5f5ca4e308ebc35ac488dbaa4: Scheduling FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06): perf score=10.126437
I20260812 06:20:29.292706 22360 maintenance_manager.cc:643] P adfa35c5f5ca4e308ebc35ac488dbaa4: FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06) complete. Timing: real 0.048s	user 0.025s	sys 0.012s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":16697,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:29.293258 22434 maintenance_manager.cc:419] P adfa35c5f5ca4e308ebc35ac488dbaa4: Scheduling FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06): perf score=2.188937
I20260812 06:20:29.305505 22360 maintenance_manager.cc:643] P adfa35c5f5ca4e308ebc35ac488dbaa4: FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06) complete. Timing: real 0.012s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4385,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:29.305964 22434 maintenance_manager.cc:419] P adfa35c5f5ca4e308ebc35ac488dbaa4: Scheduling MajorDeltaCompactionOp(d0d3231a4b844f70a7de74c666bedc06): perf score=1.000000
I20260812 06:20:29.436829 22360 maintenance_manager.cc:643] P adfa35c5f5ca4e308ebc35ac488dbaa4: MajorDeltaCompactionOp(d0d3231a4b844f70a7de74c666bedc06) complete. Timing: real 0.131s	user 0.112s	sys 0.018s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631311,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":311,"lbm_read_time_us":9876,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23842,"lbm_writes_lt_1ms":443,"mutex_wait_us":33,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5888,"update_count":2000}
I20260812 06:20:29.437556 22434 maintenance_manager.cc:419] P adfa35c5f5ca4e308ebc35ac488dbaa4: Scheduling FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06): perf score=10.126437
I20260812 06:20:29.497340 22360 maintenance_manager.cc:643] P adfa35c5f5ca4e308ebc35ac488dbaa4: FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06) complete. Timing: real 0.060s	user 0.021s	sys 0.028s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":20140,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:29.497938 22434 maintenance_manager.cc:419] P adfa35c5f5ca4e308ebc35ac488dbaa4: Scheduling FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06): perf score=2.188937
I20260812 06:20:29.508988 22360 maintenance_manager.cc:643] P adfa35c5f5ca4e308ebc35ac488dbaa4: FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4152,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:29.509552 22434 maintenance_manager.cc:419] P adfa35c5f5ca4e308ebc35ac488dbaa4: Scheduling FlushMRSOp(d0d3231a4b844f70a7de74c666bedc06): perf score=1.000000
I20260812 06:20:29.557013 22360 maintenance_manager.cc:643] P adfa35c5f5ca4e308ebc35ac488dbaa4: FlushMRSOp(d0d3231a4b844f70a7de74c666bedc06) complete. Timing: real 0.047s	user 0.034s	sys 0.000s Metrics: {"bytes_written":1152509,"cfile_init":1,"dirs.queue_time_us":111,"dirs.run_cpu_time_us":285,"dirs.run_wall_time_us":1531,"drs_written":1,"lbm_read_time_us":41,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1547,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28,"spinlock_wait_cycles":17152}
I20260812 06:20:29.557910 22434 maintenance_manager.cc:419] P adfa35c5f5ca4e308ebc35ac488dbaa4: Scheduling LogGCOp(d0d3231a4b844f70a7de74c666bedc06): free 121006375 bytes of WAL
I20260812 06:20:29.558157 22360 log_reader.cc:385] T d0d3231a4b844f70a7de74c666bedc06: removed 12 log segments from log reader
I20260812 06:20:29.558224 22360 log.cc:1079] T d0d3231a4b844f70a7de74c666bedc06 P adfa35c5f5ca4e308ebc35ac488dbaa4: Deleting log segment in path: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515627637820-22236-0/minicluster-data/ts-0-root/wals/d0d3231a4b844f70a7de74c666bedc06/wal-000000002 (ops 7-11)
I20260812 06:20:29.558275 22360 log.cc:1079] T d0d3231a4b844f70a7de74c666bedc06 P adfa35c5f5ca4e308ebc35ac488dbaa4: Deleting log segment in path: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515627637820-22236-0/minicluster-data/ts-0-root/wals/d0d3231a4b844f70a7de74c666bedc06/wal-000000003 (ops 12-16)
I20260812 06:20:29.558331 22360 log.cc:1079] T d0d3231a4b844f70a7de74c666bedc06 P adfa35c5f5ca4e308ebc35ac488dbaa4: Deleting log segment in path: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515627637820-22236-0/minicluster-data/ts-0-root/wals/d0d3231a4b844f70a7de74c666bedc06/wal-000000004 (ops 17-21)
I20260812 06:20:29.558373 22360 log.cc:1079] T d0d3231a4b844f70a7de74c666bedc06 P adfa35c5f5ca4e308ebc35ac488dbaa4: Deleting log segment in path: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515627637820-22236-0/minicluster-data/ts-0-root/wals/d0d3231a4b844f70a7de74c666bedc06/wal-000000005 (ops 22-26)
I20260812 06:20:29.558411 22360 log.cc:1079] T d0d3231a4b844f70a7de74c666bedc06 P adfa35c5f5ca4e308ebc35ac488dbaa4: Deleting log segment in path: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515627637820-22236-0/minicluster-data/ts-0-root/wals/d0d3231a4b844f70a7de74c666bedc06/wal-000000006 (ops 27-30)
I20260812 06:20:29.558451 22360 log.cc:1079] T d0d3231a4b844f70a7de74c666bedc06 P adfa35c5f5ca4e308ebc35ac488dbaa4: Deleting log segment in path: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515627637820-22236-0/minicluster-data/ts-0-root/wals/d0d3231a4b844f70a7de74c666bedc06/wal-000000007 (ops 31-35)
I20260812 06:20:29.558491 22360 log.cc:1079] T d0d3231a4b844f70a7de74c666bedc06 P adfa35c5f5ca4e308ebc35ac488dbaa4: Deleting log segment in path: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515627637820-22236-0/minicluster-data/ts-0-root/wals/d0d3231a4b844f70a7de74c666bedc06/wal-000000008 (ops 36-40)
I20260812 06:20:29.558531 22360 log.cc:1079] T d0d3231a4b844f70a7de74c666bedc06 P adfa35c5f5ca4e308ebc35ac488dbaa4: Deleting log segment in path: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515627637820-22236-0/minicluster-data/ts-0-root/wals/d0d3231a4b844f70a7de74c666bedc06/wal-000000009 (ops 41-45)
I20260812 06:20:29.558573 22360 log.cc:1079] T d0d3231a4b844f70a7de74c666bedc06 P adfa35c5f5ca4e308ebc35ac488dbaa4: Deleting log segment in path: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515627637820-22236-0/minicluster-data/ts-0-root/wals/d0d3231a4b844f70a7de74c666bedc06/wal-000000010 (ops 46-50)
I20260812 06:20:29.558633 22360 log.cc:1079] T d0d3231a4b844f70a7de74c666bedc06 P adfa35c5f5ca4e308ebc35ac488dbaa4: Deleting log segment in path: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515627637820-22236-0/minicluster-data/ts-0-root/wals/d0d3231a4b844f70a7de74c666bedc06/wal-000000011 (ops 51-55)
I20260812 06:20:29.558671 22360 log.cc:1079] T d0d3231a4b844f70a7de74c666bedc06 P adfa35c5f5ca4e308ebc35ac488dbaa4: Deleting log segment in path: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515627637820-22236-0/minicluster-data/ts-0-root/wals/d0d3231a4b844f70a7de74c666bedc06/wal-000000012 (ops 56-60)
I20260812 06:20:29.558708 22360 log.cc:1079] T d0d3231a4b844f70a7de74c666bedc06 P adfa35c5f5ca4e308ebc35ac488dbaa4: Deleting log segment in path: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515627637820-22236-0/minicluster-data/ts-0-root/wals/d0d3231a4b844f70a7de74c666bedc06/wal-000000013 (ops 61-65)
I20260812 06:20:29.585592 22360 maintenance_manager.cc:643] P adfa35c5f5ca4e308ebc35ac488dbaa4: LogGCOp(d0d3231a4b844f70a7de74c666bedc06) complete. Timing: real 0.027s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:20:29.586066 22434 maintenance_manager.cc:419] P adfa35c5f5ca4e308ebc35ac488dbaa4: Scheduling FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06): perf score=2.188937
I20260812 06:20:29.607051 22360 maintenance_manager.cc:643] P adfa35c5f5ca4e308ebc35ac488dbaa4: FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06) complete. Timing: real 0.021s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4799,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:29.607539 22434 maintenance_manager.cc:419] P adfa35c5f5ca4e308ebc35ac488dbaa4: Scheduling FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06): perf score=2.188937
I20260812 06:20:29.620025 22360 maintenance_manager.cc:643] P adfa35c5f5ca4e308ebc35ac488dbaa4: FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4800,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:29.620842 22434 maintenance_manager.cc:419] P adfa35c5f5ca4e308ebc35ac488dbaa4: Scheduling MajorDeltaCompactionOp(d0d3231a4b844f70a7de74c666bedc06): perf score=1.000000
I20260812 06:20:29.835858 22360 maintenance_manager.cc:643] P adfa35c5f5ca4e308ebc35ac488dbaa4: MajorDeltaCompactionOp(d0d3231a4b844f70a7de74c666bedc06) complete. Timing: real 0.215s	user 0.143s	sys 0.071s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836374,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1625,"lbm_read_time_us":14959,"lbm_reads_lt_1ms":674,"lbm_write_time_us":34640,"lbm_writes_lt_1ms":643,"mutex_wait_us":47,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":14976,"thread_start_us":93,"threads_started":1,"update_count":3000}
I20260812 06:20:29.836795 22434 maintenance_manager.cc:419] P adfa35c5f5ca4e308ebc35ac488dbaa4: Scheduling FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06): perf score=14.095187
I20260812 06:20:29.898357 22360 maintenance_manager.cc:643] P adfa35c5f5ca4e308ebc35ac488dbaa4: FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06) complete. Timing: real 0.061s	user 0.041s	sys 0.018s Metrics: {"bytes_written":16409898,"delete_count":0,"lbm_write_time_us":27372,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:29.899005 22434 maintenance_manager.cc:419] P adfa35c5f5ca4e308ebc35ac488dbaa4: Scheduling MajorDeltaCompactionOp(d0d3231a4b844f70a7de74c666bedc06): perf score=1.000000
I20260812 06:20:30.137519 22360 maintenance_manager.cc:643] P adfa35c5f5ca4e308ebc35ac488dbaa4: MajorDeltaCompactionOp(d0d3231a4b844f70a7de74c666bedc06) complete. Timing: real 0.238s	user 0.173s	sys 0.064s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20631189,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":835,"lbm_read_time_us":10956,"lbm_reads_lt_1ms":463,"lbm_write_time_us":38434,"lbm_writes_lt_1ms":443,"mutex_wait_us":454,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6400,"update_count":2000}
I20260812 06:20:30.138362 22434 maintenance_manager.cc:419] P adfa35c5f5ca4e308ebc35ac488dbaa4: Scheduling FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06): perf score=18.063937
I20260812 06:20:30.240566 22360 maintenance_manager.cc:643] P adfa35c5f5ca4e308ebc35ac488dbaa4: FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06) complete. Timing: real 0.102s	user 0.040s	sys 0.059s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":39704,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:30.241266 22434 maintenance_manager.cc:419] P adfa35c5f5ca4e308ebc35ac488dbaa4: Scheduling UndoDeltaBlockGCOp(d0d3231a4b844f70a7de74c666bedc06): 446 bytes on disk
I20260812 06:20:30.241935 22360 maintenance_manager.cc:643] P adfa35c5f5ca4e308ebc35ac488dbaa4: UndoDeltaBlockGCOp(d0d3231a4b844f70a7de74c666bedc06) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":122,"lbm_reads_lt_1ms":4}
I20260812 06:20:30.242537 22434 maintenance_manager.cc:419] P adfa35c5f5ca4e308ebc35ac488dbaa4: Scheduling FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06): perf score=6.157687
I20260812 06:20:30.264617 22360 maintenance_manager.cc:643] P adfa35c5f5ca4e308ebc35ac488dbaa4: FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06) complete. Timing: real 0.022s	user 0.011s	sys 0.009s Metrics: {"bytes_written":8205077,"delete_count":0,"lbm_write_time_us":9696,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:20:30.265130 22434 maintenance_manager.cc:419] P adfa35c5f5ca4e308ebc35ac488dbaa4: Scheduling MajorDeltaCompactionOp(d0d3231a4b844f70a7de74c666bedc06): perf score=1.000000
I20260812 06:20:30.537106 22360 maintenance_manager.cc:643] P adfa35c5f5ca4e308ebc35ac488dbaa4: MajorDeltaCompactionOp(d0d3231a4b844f70a7de74c666bedc06) complete. Timing: real 0.272s	user 0.197s	sys 0.072s Metrics: {"cfile_cache_miss":732,"cfile_cache_miss_bytes":32938551,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":350,"lbm_read_time_us":17893,"lbm_reads_lt_1ms":772,"lbm_write_time_us":48485,"lbm_writes_lt_1ms":743,"mutex_wait_us":104,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":10240,"update_count":3500}
I20260812 06:20:30.537941 22434 maintenance_manager.cc:419] P adfa35c5f5ca4e308ebc35ac488dbaa4: Scheduling FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06): perf score=11.118625
I20260812 06:20:30.584621 22360 maintenance_manager.cc:643] P adfa35c5f5ca4e308ebc35ac488dbaa4: FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06) complete. Timing: real 0.046s	user 0.036s	sys 0.008s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":20804,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:20:30.586241 22434 maintenance_manager.cc:419] P adfa35c5f5ca4e308ebc35ac488dbaa4: Scheduling FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06): perf score=2.188937
I20260812 06:20:30.607770 22360 maintenance_manager.cc:643] P adfa35c5f5ca4e308ebc35ac488dbaa4: FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06) complete. Timing: real 0.021s	user 0.015s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6591,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:30.608260 22434 maintenance_manager.cc:419] P adfa35c5f5ca4e308ebc35ac488dbaa4: Scheduling MajorDeltaCompactionOp(d0d3231a4b844f70a7de74c666bedc06): perf score=1.000000
I20260812 06:20:30.766906 22360 maintenance_manager.cc:643] P adfa35c5f5ca4e308ebc35ac488dbaa4: MajorDeltaCompactionOp(d0d3231a4b844f70a7de74c666bedc06) complete. Timing: real 0.158s	user 0.104s	sys 0.051s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631304,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":338,"lbm_read_time_us":10429,"lbm_reads_lt_1ms":464,"lbm_write_time_us":28128,"lbm_writes_lt_1ms":443,"mutex_wait_us":21,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8320,"update_count":2000}
I20260812 06:20:30.767592 22434 maintenance_manager.cc:419] P adfa35c5f5ca4e308ebc35ac488dbaa4: Scheduling FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06): perf score=10.126437
I20260812 06:20:30.807806 22360 maintenance_manager.cc:643] P adfa35c5f5ca4e308ebc35ac488dbaa4: FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06) complete. Timing: real 0.040s	user 0.019s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17861,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:30.808382 22434 maintenance_manager.cc:419] P adfa35c5f5ca4e308ebc35ac488dbaa4: Scheduling FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06): perf score=2.188937
I20260812 06:20:30.823354 22360 maintenance_manager.cc:643] P adfa35c5f5ca4e308ebc35ac488dbaa4: FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06) complete. Timing: real 0.015s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5977,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:30.823912 22434 maintenance_manager.cc:419] P adfa35c5f5ca4e308ebc35ac488dbaa4: Scheduling MajorDeltaCompactionOp(d0d3231a4b844f70a7de74c666bedc06): perf score=1.000000
I20260812 06:20:30.975858 22360 maintenance_manager.cc:643] P adfa35c5f5ca4e308ebc35ac488dbaa4: MajorDeltaCompactionOp(d0d3231a4b844f70a7de74c666bedc06) complete. Timing: real 0.152s	user 0.108s	sys 0.044s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1173,"lbm_read_time_us":8295,"lbm_reads_lt_1ms":472,"lbm_write_time_us":29113,"lbm_writes_lt_1ms":443,"mutex_wait_us":311,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":27392,"update_count":2000}
I20260812 06:20:30.976745 22434 maintenance_manager.cc:419] P adfa35c5f5ca4e308ebc35ac488dbaa4: Scheduling FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06): perf score=10.126437
I20260812 06:20:31.017922 22360 maintenance_manager.cc:643] P adfa35c5f5ca4e308ebc35ac488dbaa4: FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06) complete. Timing: real 0.041s	user 0.031s	sys 0.000s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":14922,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:31.018522 22434 maintenance_manager.cc:419] P adfa35c5f5ca4e308ebc35ac488dbaa4: Scheduling FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06): perf score=2.188937
I20260812 06:20:31.031549 22360 maintenance_manager.cc:643] P adfa35c5f5ca4e308ebc35ac488dbaa4: FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06) complete. Timing: real 0.013s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4810,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:31.032263 22434 maintenance_manager.cc:419] P adfa35c5f5ca4e308ebc35ac488dbaa4: Scheduling MajorDeltaCompactionOp(d0d3231a4b844f70a7de74c666bedc06): perf score=1.000000
I20260812 06:20:31.167229 22360 maintenance_manager.cc:643] P adfa35c5f5ca4e308ebc35ac488dbaa4: MajorDeltaCompactionOp(d0d3231a4b844f70a7de74c666bedc06) complete. Timing: real 0.135s	user 0.107s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631313,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":151,"lbm_read_time_us":8936,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24925,"lbm_writes_lt_1ms":443,"mutex_wait_us":43,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:20:31.167827 22434 maintenance_manager.cc:419] P adfa35c5f5ca4e308ebc35ac488dbaa4: Scheduling FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06): perf score=10.126437
I20260812 06:20:31.217059 22360 maintenance_manager.cc:643] P adfa35c5f5ca4e308ebc35ac488dbaa4: FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06) complete. Timing: real 0.049s	user 0.023s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16270,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:31.217558 22434 maintenance_manager.cc:419] P adfa35c5f5ca4e308ebc35ac488dbaa4: Scheduling FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06): perf score=2.188937
I20260812 06:20:31.229952 22360 maintenance_manager.cc:643] P adfa35c5f5ca4e308ebc35ac488dbaa4: FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4403,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:31.230813 22434 maintenance_manager.cc:419] P adfa35c5f5ca4e308ebc35ac488dbaa4: Scheduling FlushMRSOp(d0d3231a4b844f70a7de74c666bedc06): perf score=1.000000
I20260812 06:20:31.271857 22360 maintenance_manager.cc:643] P adfa35c5f5ca4e308ebc35ac488dbaa4: FlushMRSOp(d0d3231a4b844f70a7de74c666bedc06) complete. Timing: real 0.041s	user 0.034s	sys 0.004s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":58,"dirs.run_cpu_time_us":253,"dirs.run_wall_time_us":1415,"drs_written":1,"lbm_read_time_us":76,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2591,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:20:31.272687 22434 maintenance_manager.cc:419] P adfa35c5f5ca4e308ebc35ac488dbaa4: Scheduling LogGCOp(d0d3231a4b844f70a7de74c666bedc06): free 112239367 bytes of WAL
I20260812 06:20:31.272970 22360 log_reader.cc:385] T d0d3231a4b844f70a7de74c666bedc06: removed 11 log segments from log reader
I20260812 06:20:31.273042 22360 log.cc:1079] T d0d3231a4b844f70a7de74c666bedc06 P adfa35c5f5ca4e308ebc35ac488dbaa4: Deleting log segment in path: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515627637820-22236-0/minicluster-data/ts-0-root/wals/d0d3231a4b844f70a7de74c666bedc06/wal-000000014 (ops 66-70)
I20260812 06:20:31.273135 22360 log.cc:1079] T d0d3231a4b844f70a7de74c666bedc06 P adfa35c5f5ca4e308ebc35ac488dbaa4: Deleting log segment in path: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515627637820-22236-0/minicluster-data/ts-0-root/wals/d0d3231a4b844f70a7de74c666bedc06/wal-000000015 (ops 71-75)
I20260812 06:20:31.273182 22360 log.cc:1079] T d0d3231a4b844f70a7de74c666bedc06 P adfa35c5f5ca4e308ebc35ac488dbaa4: Deleting log segment in path: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515627637820-22236-0/minicluster-data/ts-0-root/wals/d0d3231a4b844f70a7de74c666bedc06/wal-000000016 (ops 76-80)
I20260812 06:20:31.273231 22360 log.cc:1079] T d0d3231a4b844f70a7de74c666bedc06 P adfa35c5f5ca4e308ebc35ac488dbaa4: Deleting log segment in path: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515627637820-22236-0/minicluster-data/ts-0-root/wals/d0d3231a4b844f70a7de74c666bedc06/wal-000000017 (ops 81-84)
I20260812 06:20:31.273293 22360 log.cc:1079] T d0d3231a4b844f70a7de74c666bedc06 P adfa35c5f5ca4e308ebc35ac488dbaa4: Deleting log segment in path: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515627637820-22236-0/minicluster-data/ts-0-root/wals/d0d3231a4b844f70a7de74c666bedc06/wal-000000018 (ops 85-89)
I20260812 06:20:31.273341 22360 log.cc:1079] T d0d3231a4b844f70a7de74c666bedc06 P adfa35c5f5ca4e308ebc35ac488dbaa4: Deleting log segment in path: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515627637820-22236-0/minicluster-data/ts-0-root/wals/d0d3231a4b844f70a7de74c666bedc06/wal-000000019 (ops 90-94)
I20260812 06:20:31.273388 22360 log.cc:1079] T d0d3231a4b844f70a7de74c666bedc06 P adfa35c5f5ca4e308ebc35ac488dbaa4: Deleting log segment in path: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515627637820-22236-0/minicluster-data/ts-0-root/wals/d0d3231a4b844f70a7de74c666bedc06/wal-000000020 (ops 95-99)
I20260812 06:20:31.273435 22360 log.cc:1079] T d0d3231a4b844f70a7de74c666bedc06 P adfa35c5f5ca4e308ebc35ac488dbaa4: Deleting log segment in path: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515627637820-22236-0/minicluster-data/ts-0-root/wals/d0d3231a4b844f70a7de74c666bedc06/wal-000000021 (ops 100-104)
I20260812 06:20:31.273483 22360 log.cc:1079] T d0d3231a4b844f70a7de74c666bedc06 P adfa35c5f5ca4e308ebc35ac488dbaa4: Deleting log segment in path: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515627637820-22236-0/minicluster-data/ts-0-root/wals/d0d3231a4b844f70a7de74c666bedc06/wal-000000022 (ops 105-109)
I20260812 06:20:31.273530 22360 log.cc:1079] T d0d3231a4b844f70a7de74c666bedc06 P adfa35c5f5ca4e308ebc35ac488dbaa4: Deleting log segment in path: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515627637820-22236-0/minicluster-data/ts-0-root/wals/d0d3231a4b844f70a7de74c666bedc06/wal-000000023 (ops 110-114)
I20260812 06:20:31.273576 22360 log.cc:1079] T d0d3231a4b844f70a7de74c666bedc06 P adfa35c5f5ca4e308ebc35ac488dbaa4: Deleting log segment in path: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515627637820-22236-0/minicluster-data/ts-0-root/wals/d0d3231a4b844f70a7de74c666bedc06/wal-000000024 (ops 115-119)
I20260812 06:20:31.302340 22360 maintenance_manager.cc:643] P adfa35c5f5ca4e308ebc35ac488dbaa4: LogGCOp(d0d3231a4b844f70a7de74c666bedc06) complete. Timing: real 0.029s	user 0.003s	sys 0.023s Metrics: {}
I20260812 06:20:31.302863 22434 maintenance_manager.cc:419] P adfa35c5f5ca4e308ebc35ac488dbaa4: Scheduling UndoDeltaBlockGCOp(d0d3231a4b844f70a7de74c666bedc06): 463 bytes on disk
I20260812 06:20:31.303761 22360 maintenance_manager.cc:643] P adfa35c5f5ca4e308ebc35ac488dbaa4: UndoDeltaBlockGCOp(d0d3231a4b844f70a7de74c666bedc06) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":133,"lbm_reads_lt_1ms":4}
I20260812 06:20:31.307107 22434 maintenance_manager.cc:419] P adfa35c5f5ca4e308ebc35ac488dbaa4: Scheduling FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06): perf score=2.188937
I20260812 06:20:31.329052 22360 maintenance_manager.cc:643] P adfa35c5f5ca4e308ebc35ac488dbaa4: FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06) complete. Timing: real 0.022s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6159,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:31.329515 22434 maintenance_manager.cc:419] P adfa35c5f5ca4e308ebc35ac488dbaa4: Scheduling FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06): perf score=2.188937
I20260812 06:20:31.340440 22360 maintenance_manager.cc:643] P adfa35c5f5ca4e308ebc35ac488dbaa4: FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4399,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:31.340914 22434 maintenance_manager.cc:419] P adfa35c5f5ca4e308ebc35ac488dbaa4: Scheduling MajorDeltaCompactionOp(d0d3231a4b844f70a7de74c666bedc06): perf score=1.000000
I20260812 06:20:31.525246 22360 maintenance_manager.cc:643] P adfa35c5f5ca4e308ebc35ac488dbaa4: MajorDeltaCompactionOp(d0d3231a4b844f70a7de74c666bedc06) complete. Timing: real 0.184s	user 0.145s	sys 0.029s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836373,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":568,"lbm_read_time_us":13817,"lbm_reads_lt_1ms":674,"lbm_write_time_us":33700,"lbm_writes_lt_1ms":643,"mutex_wait_us":27,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":29184,"thread_start_us":81,"threads_started":1,"update_count":3000}
I20260812 06:20:31.526017 22434 maintenance_manager.cc:419] P adfa35c5f5ca4e308ebc35ac488dbaa4: Scheduling FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06): perf score=14.095187
I20260812 06:20:31.578843 22360 maintenance_manager.cc:643] P adfa35c5f5ca4e308ebc35ac488dbaa4: FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06) complete. Timing: real 0.053s	user 0.027s	sys 0.015s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":18807,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:31.579649 22434 maintenance_manager.cc:419] P adfa35c5f5ca4e308ebc35ac488dbaa4: Scheduling FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06): perf score=2.188937
I20260812 06:20:31.599915 22360 maintenance_manager.cc:643] P adfa35c5f5ca4e308ebc35ac488dbaa4: FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06) complete. Timing: real 0.020s	user 0.010s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7693,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:31.600620 22434 maintenance_manager.cc:419] P adfa35c5f5ca4e308ebc35ac488dbaa4: Scheduling MajorDeltaCompactionOp(d0d3231a4b844f70a7de74c666bedc06): perf score=1.000000
I20260812 06:20:31.776861 22360 maintenance_manager.cc:643] P adfa35c5f5ca4e308ebc35ac488dbaa4: MajorDeltaCompactionOp(d0d3231a4b844f70a7de74c666bedc06) complete. Timing: real 0.176s	user 0.144s	sys 0.025s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733725,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":964,"lbm_read_time_us":13214,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33835,"lbm_writes_lt_1ms":543,"mutex_wait_us":106,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":2500}
I20260812 06:20:31.777588 22434 maintenance_manager.cc:419] P adfa35c5f5ca4e308ebc35ac488dbaa4: Scheduling FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06): perf score=14.095187
I20260812 06:20:31.840059 22360 maintenance_manager.cc:643] P adfa35c5f5ca4e308ebc35ac488dbaa4: FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06) complete. Timing: real 0.062s	user 0.033s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24554,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:31.840587 22434 maintenance_manager.cc:419] P adfa35c5f5ca4e308ebc35ac488dbaa4: Scheduling FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06): perf score=2.188937
I20260812 06:20:31.853328 22360 maintenance_manager.cc:643] P adfa35c5f5ca4e308ebc35ac488dbaa4: FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06) complete. Timing: real 0.012s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4489,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:31.853976 22434 maintenance_manager.cc:419] P adfa35c5f5ca4e308ebc35ac488dbaa4: Scheduling MajorDeltaCompactionOp(d0d3231a4b844f70a7de74c666bedc06): perf score=1.000000
I20260812 06:20:32.057355 22360 maintenance_manager.cc:643] P adfa35c5f5ca4e308ebc35ac488dbaa4: MajorDeltaCompactionOp(d0d3231a4b844f70a7de74c666bedc06) complete. Timing: real 0.203s	user 0.154s	sys 0.047s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":916,"lbm_read_time_us":14525,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33019,"lbm_writes_lt_1ms":543,"mutex_wait_us":275,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":89088,"update_count":2500}
I20260812 06:20:32.058095 22434 maintenance_manager.cc:419] P adfa35c5f5ca4e308ebc35ac488dbaa4: Scheduling FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06): perf score=14.095187
I20260812 06:20:32.124267 22360 maintenance_manager.cc:643] P adfa35c5f5ca4e308ebc35ac488dbaa4: FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06) complete. Timing: real 0.066s	user 0.048s	sys 0.013s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":29086,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:32.124835 22434 maintenance_manager.cc:419] P adfa35c5f5ca4e308ebc35ac488dbaa4: Scheduling MajorDeltaCompactionOp(d0d3231a4b844f70a7de74c666bedc06): perf score=1.000000
I20260812 06:20:32.276378 22360 maintenance_manager.cc:643] P adfa35c5f5ca4e308ebc35ac488dbaa4: MajorDeltaCompactionOp(d0d3231a4b844f70a7de74c666bedc06) complete. Timing: real 0.151s	user 0.088s	sys 0.062s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20631193,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":1511,"lbm_read_time_us":10035,"lbm_reads_lt_1ms":463,"lbm_write_time_us":25290,"lbm_writes_lt_1ms":443,"mutex_wait_us":400,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5504,"update_count":2000}
I20260812 06:20:32.277129 22434 maintenance_manager.cc:419] P adfa35c5f5ca4e308ebc35ac488dbaa4: Scheduling FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06): perf score=14.095187
I20260812 06:20:32.333304 22360 maintenance_manager.cc:643] P adfa35c5f5ca4e308ebc35ac488dbaa4: FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06) complete. Timing: real 0.056s	user 0.041s	sys 0.009s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23213,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:32.333995 22434 maintenance_manager.cc:419] P adfa35c5f5ca4e308ebc35ac488dbaa4: Scheduling FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06): perf score=2.188937
I20260812 06:20:32.346856 22360 maintenance_manager.cc:643] P adfa35c5f5ca4e308ebc35ac488dbaa4: FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06) complete. Timing: real 0.013s	user 0.001s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4699,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:32.347599 22434 maintenance_manager.cc:419] P adfa35c5f5ca4e308ebc35ac488dbaa4: Scheduling MajorDeltaCompactionOp(d0d3231a4b844f70a7de74c666bedc06): perf score=1.000000
I20260812 06:20:32.544176 22360 maintenance_manager.cc:643] P adfa35c5f5ca4e308ebc35ac488dbaa4: MajorDeltaCompactionOp(d0d3231a4b844f70a7de74c666bedc06) complete. Timing: real 0.196s	user 0.122s	sys 0.065s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733724,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1298,"lbm_read_time_us":9828,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34325,"lbm_writes_lt_1ms":543,"mutex_wait_us":384,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14848,"update_count":2500}
I20260812 06:20:32.544993 22434 maintenance_manager.cc:419] P adfa35c5f5ca4e308ebc35ac488dbaa4: Scheduling FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06): perf score=14.095187
I20260812 06:20:32.604341 22360 maintenance_manager.cc:643] P adfa35c5f5ca4e308ebc35ac488dbaa4: FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06) complete. Timing: real 0.059s	user 0.031s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23412,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:32.605212 22434 maintenance_manager.cc:419] P adfa35c5f5ca4e308ebc35ac488dbaa4: Scheduling FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06): perf score=2.188937
I20260812 06:20:32.623152 22360 maintenance_manager.cc:643] P adfa35c5f5ca4e308ebc35ac488dbaa4: FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06) complete. Timing: real 0.017s	user 0.013s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6693,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:32.623808 22434 maintenance_manager.cc:419] P adfa35c5f5ca4e308ebc35ac488dbaa4: Scheduling MajorDeltaCompactionOp(d0d3231a4b844f70a7de74c666bedc06): perf score=1.000000
I20260812 06:20:32.806793 22360 maintenance_manager.cc:643] P adfa35c5f5ca4e308ebc35ac488dbaa4: MajorDeltaCompactionOp(d0d3231a4b844f70a7de74c666bedc06) complete. Timing: real 0.183s	user 0.146s	sys 0.025s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733722,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1153,"lbm_read_time_us":11987,"lbm_reads_lt_1ms":572,"lbm_write_time_us":35319,"lbm_writes_lt_1ms":543,"mutex_wait_us":400,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11904,"update_count":2500}
I20260812 06:20:32.807677 22434 maintenance_manager.cc:419] P adfa35c5f5ca4e308ebc35ac488dbaa4: Scheduling FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06): perf score=14.095187
I20260812 06:20:32.859638 22360 maintenance_manager.cc:643] P adfa35c5f5ca4e308ebc35ac488dbaa4: FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06) complete. Timing: real 0.052s	user 0.027s	sys 0.024s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":22423,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:32.860179 22434 maintenance_manager.cc:419] P adfa35c5f5ca4e308ebc35ac488dbaa4: Scheduling FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06): perf score=2.188937
I20260812 06:20:32.877568 22360 maintenance_manager.cc:643] P adfa35c5f5ca4e308ebc35ac488dbaa4: FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06) complete. Timing: real 0.017s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5699,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:32.878211 22434 maintenance_manager.cc:419] P adfa35c5f5ca4e308ebc35ac488dbaa4: Scheduling FlushMRSOp(d0d3231a4b844f70a7de74c666bedc06): perf score=1.000000
I20260812 06:20:32.909101 22360 maintenance_manager.cc:643] P adfa35c5f5ca4e308ebc35ac488dbaa4: FlushMRSOp(d0d3231a4b844f70a7de74c666bedc06) complete. Timing: real 0.031s	user 0.026s	sys 0.003s Metrics: {"bytes_written":1316414,"cfile_init":1,"dirs.queue_time_us":102,"dirs.run_cpu_time_us":240,"dirs.run_wall_time_us":1835,"drs_written":1,"lbm_read_time_us":72,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1851,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:20:32.910742 22434 maintenance_manager.cc:419] P adfa35c5f5ca4e308ebc35ac488dbaa4: Scheduling LogGCOp(d0d3231a4b844f70a7de74c666bedc06): free 129320741 bytes of WAL
I20260812 06:20:32.911123 22360 log_reader.cc:385] T d0d3231a4b844f70a7de74c666bedc06: removed 13 log segments from log reader
I20260812 06:20:32.911213 22360 log.cc:1079] T d0d3231a4b844f70a7de74c666bedc06 P adfa35c5f5ca4e308ebc35ac488dbaa4: Deleting log segment in path: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515627637820-22236-0/minicluster-data/ts-0-root/wals/d0d3231a4b844f70a7de74c666bedc06/wal-000000025 (ops 120-124)
I20260812 06:20:32.911355 22360 log.cc:1079] T d0d3231a4b844f70a7de74c666bedc06 P adfa35c5f5ca4e308ebc35ac488dbaa4: Deleting log segment in path: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515627637820-22236-0/minicluster-data/ts-0-root/wals/d0d3231a4b844f70a7de74c666bedc06/wal-000000026 (ops 125-128)
I20260812 06:20:32.911434 22360 log.cc:1079] T d0d3231a4b844f70a7de74c666bedc06 P adfa35c5f5ca4e308ebc35ac488dbaa4: Deleting log segment in path: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515627637820-22236-0/minicluster-data/ts-0-root/wals/d0d3231a4b844f70a7de74c666bedc06/wal-000000027 (ops 129-133)
I20260812 06:20:32.911550 22360 log.cc:1079] T d0d3231a4b844f70a7de74c666bedc06 P adfa35c5f5ca4e308ebc35ac488dbaa4: Deleting log segment in path: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515627637820-22236-0/minicluster-data/ts-0-root/wals/d0d3231a4b844f70a7de74c666bedc06/wal-000000028 (ops 134-138)
I20260812 06:20:32.911623 22360 log.cc:1079] T d0d3231a4b844f70a7de74c666bedc06 P adfa35c5f5ca4e308ebc35ac488dbaa4: Deleting log segment in path: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515627637820-22236-0/minicluster-data/ts-0-root/wals/d0d3231a4b844f70a7de74c666bedc06/wal-000000029 (ops 139-143)
I20260812 06:20:32.911661 22360 log.cc:1079] T d0d3231a4b844f70a7de74c666bedc06 P adfa35c5f5ca4e308ebc35ac488dbaa4: Deleting log segment in path: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515627637820-22236-0/minicluster-data/ts-0-root/wals/d0d3231a4b844f70a7de74c666bedc06/wal-000000030 (ops 144-148)
I20260812 06:20:32.911705 22360 log.cc:1079] T d0d3231a4b844f70a7de74c666bedc06 P adfa35c5f5ca4e308ebc35ac488dbaa4: Deleting log segment in path: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515627637820-22236-0/minicluster-data/ts-0-root/wals/d0d3231a4b844f70a7de74c666bedc06/wal-000000031 (ops 149-153)
I20260812 06:20:32.911809 22360 log.cc:1079] T d0d3231a4b844f70a7de74c666bedc06 P adfa35c5f5ca4e308ebc35ac488dbaa4: Deleting log segment in path: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515627637820-22236-0/minicluster-data/ts-0-root/wals/d0d3231a4b844f70a7de74c666bedc06/wal-000000032 (ops 154-158)
I20260812 06:20:32.911875 22360 log.cc:1079] T d0d3231a4b844f70a7de74c666bedc06 P adfa35c5f5ca4e308ebc35ac488dbaa4: Deleting log segment in path: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515627637820-22236-0/minicluster-data/ts-0-root/wals/d0d3231a4b844f70a7de74c666bedc06/wal-000000033 (ops 159-162)
I20260812 06:20:32.911914 22360 log.cc:1079] T d0d3231a4b844f70a7de74c666bedc06 P adfa35c5f5ca4e308ebc35ac488dbaa4: Deleting log segment in path: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515627637820-22236-0/minicluster-data/ts-0-root/wals/d0d3231a4b844f70a7de74c666bedc06/wal-000000034 (ops 163-167)
I20260812 06:20:32.912024 22360 log.cc:1079] T d0d3231a4b844f70a7de74c666bedc06 P adfa35c5f5ca4e308ebc35ac488dbaa4: Deleting log segment in path: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515627637820-22236-0/minicluster-data/ts-0-root/wals/d0d3231a4b844f70a7de74c666bedc06/wal-000000035 (ops 168-172)
I20260812 06:20:32.912067 22360 log.cc:1079] T d0d3231a4b844f70a7de74c666bedc06 P adfa35c5f5ca4e308ebc35ac488dbaa4: Deleting log segment in path: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515627637820-22236-0/minicluster-data/ts-0-root/wals/d0d3231a4b844f70a7de74c666bedc06/wal-000000036 (ops 173-177)
I20260812 06:20:32.912133 22360 log.cc:1079] T d0d3231a4b844f70a7de74c666bedc06 P adfa35c5f5ca4e308ebc35ac488dbaa4: Deleting log segment in path: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515627637820-22236-0/minicluster-data/ts-0-root/wals/d0d3231a4b844f70a7de74c666bedc06/wal-000000037 (ops 178-182)
I20260812 06:20:32.941793 22360 maintenance_manager.cc:643] P adfa35c5f5ca4e308ebc35ac488dbaa4: LogGCOp(d0d3231a4b844f70a7de74c666bedc06) complete. Timing: real 0.031s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:20:32.942363 22434 maintenance_manager.cc:419] P adfa35c5f5ca4e308ebc35ac488dbaa4: Scheduling FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06): perf score=6.157687
I20260812 06:20:32.975576 22360 maintenance_manager.cc:643] P adfa35c5f5ca4e308ebc35ac488dbaa4: FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06) complete. Timing: real 0.033s	user 0.025s	sys 0.004s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":12631,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:20:32.976212 22434 maintenance_manager.cc:419] P adfa35c5f5ca4e308ebc35ac488dbaa4: Scheduling LogGCOp(d0d3231a4b844f70a7de74c666bedc06): free 12017949 bytes of WAL
I20260812 06:20:32.976477 22360 log_reader.cc:385] T d0d3231a4b844f70a7de74c666bedc06: removed 1 log segments from log reader
I20260812 06:20:32.976567 22360 log.cc:1079] T d0d3231a4b844f70a7de74c666bedc06 P adfa35c5f5ca4e308ebc35ac488dbaa4: Deleting log segment in path: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515627637820-22236-0/minicluster-data/ts-0-root/wals/d0d3231a4b844f70a7de74c666bedc06/wal-000000038 (ops 183-187)
I20260812 06:20:32.979071 22360 maintenance_manager.cc:643] P adfa35c5f5ca4e308ebc35ac488dbaa4: LogGCOp(d0d3231a4b844f70a7de74c666bedc06) complete. Timing: real 0.003s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:20:32.979471 22434 maintenance_manager.cc:419] P adfa35c5f5ca4e308ebc35ac488dbaa4: Scheduling UndoDeltaBlockGCOp(d0d3231a4b844f70a7de74c666bedc06): 492 bytes on disk
I20260812 06:20:32.980223 22360 maintenance_manager.cc:643] P adfa35c5f5ca4e308ebc35ac488dbaa4: UndoDeltaBlockGCOp(d0d3231a4b844f70a7de74c666bedc06) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":64,"lbm_reads_lt_1ms":4}
I20260812 06:20:32.981251 22434 maintenance_manager.cc:419] P adfa35c5f5ca4e308ebc35ac488dbaa4: Scheduling FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06): perf score=1.000000
I20260812 06:20:32.990500 22360 maintenance_manager.cc:643] P adfa35c5f5ca4e308ebc35ac488dbaa4: FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06) complete. Timing: real 0.009s	user 0.004s	sys 0.000s Metrics: {"bytes_written":1271931,"delete_count":0,"lbm_write_time_us":1464,"lbm_writes_lt_1ms":34,"reinsert_count":0,"update_count":155}
I20260812 06:20:32.991101 22434 maintenance_manager.cc:419] P adfa35c5f5ca4e308ebc35ac488dbaa4: Scheduling FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06): perf score=1.196750
I20260812 06:20:32.999630 22360 maintenance_manager.cc:643] P adfa35c5f5ca4e308ebc35ac488dbaa4: FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06) complete. Timing: real 0.008s	user 0.007s	sys 0.000s Metrics: {"bytes_written":2830880,"delete_count":0,"lbm_write_time_us":2902,"lbm_writes_lt_1ms":72,"reinsert_count":0,"update_count":345}
I20260812 06:20:33.000231 22434 maintenance_manager.cc:419] P adfa35c5f5ca4e308ebc35ac488dbaa4: Scheduling MajorDeltaCompactionOp(d0d3231a4b844f70a7de74c666bedc06): perf score=1.000000
I20260812 06:20:33.303807 22360 maintenance_manager.cc:643] P adfa35c5f5ca4e308ebc35ac488dbaa4: MajorDeltaCompactionOp(d0d3231a4b844f70a7de74c666bedc06) complete. Timing: real 0.303s	user 0.180s	sys 0.119s Metrics: {"cfile_cache_miss":835,"cfile_cache_miss_bytes":37041222,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":831,"lbm_read_time_us":21882,"lbm_reads_lt_1ms":875,"lbm_write_time_us":49907,"lbm_writes_lt_1ms":843,"mutex_wait_us":26,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":17280,"thread_start_us":97,"threads_started":1,"update_count":4000}
I20260812 06:20:33.304720 22434 maintenance_manager.cc:419] P adfa35c5f5ca4e308ebc35ac488dbaa4: Scheduling FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06): perf score=18.063937
I20260812 06:20:33.385627 22236 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.429s	user 1.983s	sys 0.165s
I20260812 06:20:33.389848 22360 maintenance_manager.cc:643] P adfa35c5f5ca4e308ebc35ac488dbaa4: FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06) complete. Timing: real 0.085s	user 0.036s	sys 0.031s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":31580,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":501,"reinsert_count":0,"update_count":2500}
I20260812 06:20:33.390479 22434 maintenance_manager.cc:419] P adfa35c5f5ca4e308ebc35ac488dbaa4: Scheduling FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06): perf score=2.188937
I20260812 06:20:33.407392 22360 maintenance_manager.cc:643] P adfa35c5f5ca4e308ebc35ac488dbaa4: FlushDeltaMemStoresOp(d0d3231a4b844f70a7de74c666bedc06) complete. Timing: real 0.017s	user 0.015s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6478,"lbm_writes_lt_1ms":103,"reinsert_count":0,"spinlock_wait_cycles":1920,"update_count":500}
I20260812 06:20:33.407991 22434 maintenance_manager.cc:419] P adfa35c5f5ca4e308ebc35ac488dbaa4: Scheduling MajorDeltaCompactionOp(d0d3231a4b844f70a7de74c666bedc06): perf score=1.000000
I20260812 06:20:33.473104 22236 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.087s	user 0.001s	sys 0.000s
I20260812 06:20:33.473812 22236 tablet_server.cc:179] TabletServer@127.21.183.1:0 shutting down...
I20260812 06:20:33.563715 22360 maintenance_manager.cc:643] P adfa35c5f5ca4e308ebc35ac488dbaa4: MajorDeltaCompactionOp(d0d3231a4b844f70a7de74c666bedc06) complete. Timing: real 0.156s	user 0.091s	sys 0.064s Metrics: {"cfile_cache_hit":253,"cfile_cache_hit_bytes":10341453,"cfile_cache_miss":379,"cfile_cache_miss_bytes":18494684,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":687,"lbm_read_time_us":8309,"lbm_reads_lt_1ms":411,"lbm_write_time_us":30013,"lbm_writes_lt_1ms":643,"mutex_wait_us":49,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":132736,"update_count":3000}
I20260812 06:20:33.564467 22236 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:33.564905 22236 tablet_replica.cc:333] T d0d3231a4b844f70a7de74c666bedc06 P adfa35c5f5ca4e308ebc35ac488dbaa4: stopping tablet replica
I20260812 06:20:33.565095 22236 raft_consensus.cc:2243] T d0d3231a4b844f70a7de74c666bedc06 P adfa35c5f5ca4e308ebc35ac488dbaa4 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:33.565303 22236 raft_consensus.cc:2272] T d0d3231a4b844f70a7de74c666bedc06 P adfa35c5f5ca4e308ebc35ac488dbaa4 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:33.581091 22236 tablet_server.cc:196] TabletServer@127.21.183.1:0 shutdown complete.
I20260812 06:20:33.617308 22236 master.cc:562] Master@127.21.183.62:40131 shutting down...
I20260812 06:20:33.621798 22236 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 5f51b69f8d45478b87cfb9c02e8d6f0c [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:33.622042 22236 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 5f51b69f8d45478b87cfb9c02e8d6f0c [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:33.622143 22236 tablet_replica.cc:333] T 00000000000000000000000000000000 P 5f51b69f8d45478b87cfb9c02e8d6f0c: stopping tablet replica
I20260812 06:20:33.636408 22236 master.cc:584] Master@127.21.183.62:40131 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (6086 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:20:33.748170 22236 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.21.183.62:44431
I20260812 06:20:33.748656 22236 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:33.751044 22468 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:33.751232 22469 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:33.751251 22236 server_base.cc:1061] running on GCE node
W20260812 06:20:33.751061 22472 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:33.751642 22236 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:33.751689 22236 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:33.751704 22236 hybrid_clock.cc:648] HybridClock initialized: now 1786515633751704 us; error 0 us; skew 500 ppm
I20260812 06:20:33.752777 22236 webserver.cc:533] Webserver started at http://127.21.183.62:35497/ using document root <none> and password file <none>
I20260812 06:20:33.752990 22236 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:33.753041 22236 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:33.753152 22236 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:33.753602 22236 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515627637820-22236-0/minicluster-data/master-0-root/instance:
uuid: "518a5727d2bc45b998559e5e3916911a"
format_stamp: "Formatted at 2026-08-12 06:20:33 on dist-test-slave-dhph"
I20260812 06:20:33.756557 22236 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.000s	sys 0.003s
I20260812 06:20:33.757761 22478 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:33.758082 22236 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:20:33.758176 22236 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515627637820-22236-0/minicluster-data/master-0-root
uuid: "518a5727d2bc45b998559e5e3916911a"
format_stamp: "Formatted at 2026-08-12 06:20:33 on dist-test-slave-dhph"
I20260812 06:20:33.758246 22236 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515627637820-22236-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515627637820-22236-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515627637820-22236-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:33.772248 22236 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:33.772658 22236 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:33.777051 22236 rpc_server.cc:307] RPC server started. Bound to: 127.21.183.62:44431
I20260812 06:20:33.778499 22541 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.21.183.62:44431 every 8 connection(s)
I20260812 06:20:33.782471 22542 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:33.784543 22542 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 518a5727d2bc45b998559e5e3916911a: Bootstrap starting.
I20260812 06:20:33.785351 22542 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 518a5727d2bc45b998559e5e3916911a: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:33.786525 22542 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 518a5727d2bc45b998559e5e3916911a: No bootstrap required, opened a new log
I20260812 06:20:33.786999 22542 raft_consensus.cc:359] T 00000000000000000000000000000000 P 518a5727d2bc45b998559e5e3916911a [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "518a5727d2bc45b998559e5e3916911a" member_type: VOTER }
I20260812 06:20:33.787097 22542 raft_consensus.cc:385] T 00000000000000000000000000000000 P 518a5727d2bc45b998559e5e3916911a [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:33.787122 22542 raft_consensus.cc:740] T 00000000000000000000000000000000 P 518a5727d2bc45b998559e5e3916911a [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 518a5727d2bc45b998559e5e3916911a, State: Initialized, Role: FOLLOWER
I20260812 06:20:33.787241 22542 consensus_queue.cc:260] T 00000000000000000000000000000000 P 518a5727d2bc45b998559e5e3916911a [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: "518a5727d2bc45b998559e5e3916911a" member_type: VOTER }
I20260812 06:20:33.787307 22542 raft_consensus.cc:399] T 00000000000000000000000000000000 P 518a5727d2bc45b998559e5e3916911a [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:33.787331 22542 raft_consensus.cc:493] T 00000000000000000000000000000000 P 518a5727d2bc45b998559e5e3916911a [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:33.787370 22542 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 518a5727d2bc45b998559e5e3916911a [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:33.788316 22542 raft_consensus.cc:515] T 00000000000000000000000000000000 P 518a5727d2bc45b998559e5e3916911a [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "518a5727d2bc45b998559e5e3916911a" member_type: VOTER }
I20260812 06:20:33.788437 22542 leader_election.cc:304] T 00000000000000000000000000000000 P 518a5727d2bc45b998559e5e3916911a [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: 518a5727d2bc45b998559e5e3916911a; no voters: 
I20260812 06:20:33.788611 22542 leader_election.cc:290] T 00000000000000000000000000000000 P 518a5727d2bc45b998559e5e3916911a [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:33.788766 22546 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 518a5727d2bc45b998559e5e3916911a [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:33.789004 22546 raft_consensus.cc:697] T 00000000000000000000000000000000 P 518a5727d2bc45b998559e5e3916911a [term 1 LEADER]: Becoming Leader. State: Replica: 518a5727d2bc45b998559e5e3916911a, State: Running, Role: LEADER
I20260812 06:20:33.789119 22542 sys_catalog.cc:565] T 00000000000000000000000000000000 P 518a5727d2bc45b998559e5e3916911a [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:33.789150 22546 consensus_queue.cc:237] T 00000000000000000000000000000000 P 518a5727d2bc45b998559e5e3916911a [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: "518a5727d2bc45b998559e5e3916911a" member_type: VOTER }
I20260812 06:20:33.789680 22547 sys_catalog.cc:455] T 00000000000000000000000000000000 P 518a5727d2bc45b998559e5e3916911a [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "518a5727d2bc45b998559e5e3916911a" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "518a5727d2bc45b998559e5e3916911a" member_type: VOTER } }
I20260812 06:20:33.789734 22548 sys_catalog.cc:455] T 00000000000000000000000000000000 P 518a5727d2bc45b998559e5e3916911a [sys.catalog]: SysCatalogTable state changed. Reason: New leader 518a5727d2bc45b998559e5e3916911a. Latest consensus state: current_term: 1 leader_uuid: "518a5727d2bc45b998559e5e3916911a" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "518a5727d2bc45b998559e5e3916911a" member_type: VOTER } }
I20260812 06:20:33.789853 22547 sys_catalog.cc:458] T 00000000000000000000000000000000 P 518a5727d2bc45b998559e5e3916911a [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:33.789873 22548 sys_catalog.cc:458] T 00000000000000000000000000000000 P 518a5727d2bc45b998559e5e3916911a [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:33.790524 22554 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:33.791491 22554 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:33.791703 22236 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:33.793573 22554 catalog_manager.cc:1383] Generated new cluster ID: a66bd4118bb4418d9f2ef18783352243
I20260812 06:20:33.793622 22554 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:33.813757 22554 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:33.814539 22554 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:33.824316 22554 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 518a5727d2bc45b998559e5e3916911a: Generated new TSK 0
I20260812 06:20:33.824590 22554 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:33.856792 22236 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:33.859407 22570 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:33.859527 22567 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:33.859408 22236 server_base.cc:1061] running on GCE node
W20260812 06:20:33.859478 22568 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:33.860165 22236 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:33.860236 22236 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:33.860263 22236 hybrid_clock.cc:648] HybridClock initialized: now 1786515633860262 us; error 0 us; skew 500 ppm
I20260812 06:20:33.861400 22236 webserver.cc:533] Webserver started at http://127.21.183.1:42797/ using document root <none> and password file <none>
I20260812 06:20:33.861614 22236 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:33.861757 22236 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:33.861845 22236 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:33.862291 22236 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515627637820-22236-0/minicluster-data/ts-0-root/instance:
uuid: "1fe6a521c1804962aa6db14ed3e0eb34"
format_stamp: "Formatted at 2026-08-12 06:20:33 on dist-test-slave-dhph"
I20260812 06:20:33.864244 22236 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:20:33.865613 22577 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:33.866001 22236 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:33.866117 22236 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515627637820-22236-0/minicluster-data/ts-0-root
uuid: "1fe6a521c1804962aa6db14ed3e0eb34"
format_stamp: "Formatted at 2026-08-12 06:20:33 on dist-test-slave-dhph"
I20260812 06:20:33.866220 22236 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515627637820-22236-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515627637820-22236-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515627637820-22236-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:33.888314 22236 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:33.888839 22236 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:33.889246 22236 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:33.889786 22236 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:33.889864 22236 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:33.889936 22236 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:33.889977 22236 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:33.895408 22236 rpc_server.cc:307] RPC server started. Bound to: 127.21.183.1:33637
I20260812 06:20:33.897300 22650 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.21.183.1:33637 every 8 connection(s)
I20260812 06:20:33.908970 22651 heartbeater.cc:344] Connected to a master server at 127.21.183.62:44431
I20260812 06:20:33.909142 22651 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:33.909474 22651 heartbeater.cc:507] Master 127.21.183.62:44431 requested a full tablet report, sending...
I20260812 06:20:33.910336 22498 ts_manager.cc:194] Registered new tserver with Master: 1fe6a521c1804962aa6db14ed3e0eb34 (127.21.183.1:33637)
I20260812 06:20:33.911239 22498 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:49350
I20260812 06:20:33.911239 22236 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.014720965s
I20260812 06:20:33.921489 22498 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:49366:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:20:33.934348 22610 tablet_service.cc:1511] Processing CreateTablet for tablet e146f4cac25e43e8aaf1749f1bd43ae5 (DEFAULT_TABLE table=heavy-update-compaction-test [id=06e913f7f0cd4deda1acde37a9a4dbbc]), partition=
I20260812 06:20:33.934759 22610 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet e146f4cac25e43e8aaf1749f1bd43ae5. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:33.937245 22666 tablet_bootstrap.cc:492] T e146f4cac25e43e8aaf1749f1bd43ae5 P 1fe6a521c1804962aa6db14ed3e0eb34: Bootstrap starting.
I20260812 06:20:33.938192 22666 tablet_bootstrap.cc:654] T e146f4cac25e43e8aaf1749f1bd43ae5 P 1fe6a521c1804962aa6db14ed3e0eb34: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:33.940045 22666 tablet_bootstrap.cc:492] T e146f4cac25e43e8aaf1749f1bd43ae5 P 1fe6a521c1804962aa6db14ed3e0eb34: No bootstrap required, opened a new log
I20260812 06:20:33.940219 22666 ts_tablet_manager.cc:1403] T e146f4cac25e43e8aaf1749f1bd43ae5 P 1fe6a521c1804962aa6db14ed3e0eb34: Time spent bootstrapping tablet: real 0.003s	user 0.000s	sys 0.002s
I20260812 06:20:33.940776 22666 raft_consensus.cc:359] T e146f4cac25e43e8aaf1749f1bd43ae5 P 1fe6a521c1804962aa6db14ed3e0eb34 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1fe6a521c1804962aa6db14ed3e0eb34" member_type: VOTER last_known_addr { host: "127.21.183.1" port: 33637 } }
I20260812 06:20:33.940923 22666 raft_consensus.cc:385] T e146f4cac25e43e8aaf1749f1bd43ae5 P 1fe6a521c1804962aa6db14ed3e0eb34 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:33.940976 22666 raft_consensus.cc:740] T e146f4cac25e43e8aaf1749f1bd43ae5 P 1fe6a521c1804962aa6db14ed3e0eb34 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 1fe6a521c1804962aa6db14ed3e0eb34, State: Initialized, Role: FOLLOWER
I20260812 06:20:33.941154 22666 consensus_queue.cc:260] T e146f4cac25e43e8aaf1749f1bd43ae5 P 1fe6a521c1804962aa6db14ed3e0eb34 [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: "1fe6a521c1804962aa6db14ed3e0eb34" member_type: VOTER last_known_addr { host: "127.21.183.1" port: 33637 } }
I20260812 06:20:33.941262 22666 raft_consensus.cc:399] T e146f4cac25e43e8aaf1749f1bd43ae5 P 1fe6a521c1804962aa6db14ed3e0eb34 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:33.941310 22666 raft_consensus.cc:493] T e146f4cac25e43e8aaf1749f1bd43ae5 P 1fe6a521c1804962aa6db14ed3e0eb34 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:33.941370 22666 raft_consensus.cc:3060] T e146f4cac25e43e8aaf1749f1bd43ae5 P 1fe6a521c1804962aa6db14ed3e0eb34 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:33.942245 22666 raft_consensus.cc:515] T e146f4cac25e43e8aaf1749f1bd43ae5 P 1fe6a521c1804962aa6db14ed3e0eb34 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1fe6a521c1804962aa6db14ed3e0eb34" member_type: VOTER last_known_addr { host: "127.21.183.1" port: 33637 } }
I20260812 06:20:33.942426 22666 leader_election.cc:304] T e146f4cac25e43e8aaf1749f1bd43ae5 P 1fe6a521c1804962aa6db14ed3e0eb34 [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: 1fe6a521c1804962aa6db14ed3e0eb34; no voters: 
I20260812 06:20:33.942731 22666 leader_election.cc:290] T e146f4cac25e43e8aaf1749f1bd43ae5 P 1fe6a521c1804962aa6db14ed3e0eb34 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:33.942976 22669 raft_consensus.cc:2804] T e146f4cac25e43e8aaf1749f1bd43ae5 P 1fe6a521c1804962aa6db14ed3e0eb34 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:33.943141 22666 ts_tablet_manager.cc:1434] T e146f4cac25e43e8aaf1749f1bd43ae5 P 1fe6a521c1804962aa6db14ed3e0eb34: Time spent starting tablet: real 0.003s	user 0.000s	sys 0.004s
I20260812 06:20:33.943181 22651 heartbeater.cc:499] Master 127.21.183.62:44431 was elected leader, sending a full tablet report...
I20260812 06:20:33.943282 22669 raft_consensus.cc:697] T e146f4cac25e43e8aaf1749f1bd43ae5 P 1fe6a521c1804962aa6db14ed3e0eb34 [term 1 LEADER]: Becoming Leader. State: Replica: 1fe6a521c1804962aa6db14ed3e0eb34, State: Running, Role: LEADER
I20260812 06:20:33.943481 22669 consensus_queue.cc:237] T e146f4cac25e43e8aaf1749f1bd43ae5 P 1fe6a521c1804962aa6db14ed3e0eb34 [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: "1fe6a521c1804962aa6db14ed3e0eb34" member_type: VOTER last_known_addr { host: "127.21.183.1" port: 33637 } }
I20260812 06:20:33.944934 22497 catalog_manager.cc:5719] T e146f4cac25e43e8aaf1749f1bd43ae5 P 1fe6a521c1804962aa6db14ed3e0eb34 reported cstate change: term changed from 0 to 1, leader changed from <none> to 1fe6a521c1804962aa6db14ed3e0eb34 (127.21.183.1). New cstate: current_term: 1 leader_uuid: "1fe6a521c1804962aa6db14ed3e0eb34" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1fe6a521c1804962aa6db14ed3e0eb34" member_type: VOTER last_known_addr { host: "127.21.183.1" port: 33637 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:34.012254 22236 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.060s	user 0.024s	sys 0.001s
I20260812 06:20:34.148126 22652 maintenance_manager.cc:419] P 1fe6a521c1804962aa6db14ed3e0eb34: Scheduling FlushMRSOp(e146f4cac25e43e8aaf1749f1bd43ae5): perf score=15.086190
I20260812 06:20:34.308790 22582 maintenance_manager.cc:643] P 1fe6a521c1804962aa6db14ed3e0eb34: FlushMRSOp(e146f4cac25e43e8aaf1749f1bd43ae5) complete. Timing: real 0.160s	user 0.110s	sys 0.043s Metrics: {"bytes_written":11897249,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":90,"dirs.run_cpu_time_us":194,"dirs.run_wall_time_us":935,"drs_written":1,"lbm_read_time_us":59,"lbm_reads_lt_1ms":4,"lbm_write_time_us":35381,"lbm_writes_lt_1ms":657,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1450}
I20260812 06:20:34.309522 22652 maintenance_manager.cc:419] P 1fe6a521c1804962aa6db14ed3e0eb34: Scheduling LogGCOp(e146f4cac25e43e8aaf1749f1bd43ae5): free 20743880 bytes of WAL
I20260812 06:20:34.309764 22582 log_reader.cc:385] T e146f4cac25e43e8aaf1749f1bd43ae5: removed 2 log segments from log reader
I20260812 06:20:34.309810 22582 log.cc:1079] T e146f4cac25e43e8aaf1749f1bd43ae5 P 1fe6a521c1804962aa6db14ed3e0eb34: Deleting log segment in path: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515627637820-22236-0/minicluster-data/ts-0-root/wals/e146f4cac25e43e8aaf1749f1bd43ae5/wal-000000001 (ops 1-6)
I20260812 06:20:34.309841 22582 log.cc:1079] T e146f4cac25e43e8aaf1749f1bd43ae5 P 1fe6a521c1804962aa6db14ed3e0eb34: Deleting log segment in path: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515627637820-22236-0/minicluster-data/ts-0-root/wals/e146f4cac25e43e8aaf1749f1bd43ae5/wal-000000002 (ops 7-11)
I20260812 06:20:34.315066 22582 maintenance_manager.cc:643] P 1fe6a521c1804962aa6db14ed3e0eb34: LogGCOp(e146f4cac25e43e8aaf1749f1bd43ae5) complete. Timing: real 0.005s	user 0.000s	sys 0.005s Metrics: {}
I20260812 06:20:34.315629 22652 maintenance_manager.cc:419] P 1fe6a521c1804962aa6db14ed3e0eb34: Scheduling UndoDeltaBlockGCOp(e146f4cac25e43e8aaf1749f1bd43ae5): 12719219 bytes on disk
I20260812 06:20:34.316161 22582 maintenance_manager.cc:643] P 1fe6a521c1804962aa6db14ed3e0eb34: UndoDeltaBlockGCOp(e146f4cac25e43e8aaf1749f1bd43ae5) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":68,"lbm_reads_lt_1ms":4}
I20260812 06:20:34.316620 22652 maintenance_manager.cc:419] P 1fe6a521c1804962aa6db14ed3e0eb34: Scheduling FlushDeltaMemStoresOp(e146f4cac25e43e8aaf1749f1bd43ae5): perf score=2.188937
I20260812 06:20:34.328040 22582 maintenance_manager.cc:643] P 1fe6a521c1804962aa6db14ed3e0eb34: FlushDeltaMemStoresOp(e146f4cac25e43e8aaf1749f1bd43ae5) complete. Timing: real 0.011s	user 0.001s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4227,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:34.328639 22652 maintenance_manager.cc:419] P 1fe6a521c1804962aa6db14ed3e0eb34: Scheduling MajorDeltaCompactionOp(e146f4cac25e43e8aaf1749f1bd43ae5): perf score=1.000000
I20260812 06:20:34.481894 22582 maintenance_manager.cc:643] P 1fe6a521c1804962aa6db14ed3e0eb34: MajorDeltaCompactionOp(e146f4cac25e43e8aaf1749f1bd43ae5) complete. Timing: real 0.153s	user 0.089s	sys 0.064s Metrics: {"cfile_cache_miss":422,"cfile_cache_miss_bytes":20262036,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":648,"lbm_read_time_us":11206,"lbm_reads_lt_1ms":454,"lbm_write_time_us":22739,"lbm_writes_lt_1ms":433,"peak_mem_usage":49238594,"reinsert_count":0,"spinlock_wait_cycles":3200,"thread_start_us":300,"threads_started":5,"update_count":1950}
I20260812 06:20:34.482555 22652 maintenance_manager.cc:419] P 1fe6a521c1804962aa6db14ed3e0eb34: Scheduling FlushDeltaMemStoresOp(e146f4cac25e43e8aaf1749f1bd43ae5): perf score=10.126437
I20260812 06:20:34.528996 22582 maintenance_manager.cc:643] P 1fe6a521c1804962aa6db14ed3e0eb34: FlushDeltaMemStoresOp(e146f4cac25e43e8aaf1749f1bd43ae5) complete. Timing: real 0.046s	user 0.018s	sys 0.017s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15899,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:20:34.529521 22652 maintenance_manager.cc:419] P 1fe6a521c1804962aa6db14ed3e0eb34: Scheduling FlushDeltaMemStoresOp(e146f4cac25e43e8aaf1749f1bd43ae5): perf score=2.188937
I20260812 06:20:34.540126 22582 maintenance_manager.cc:643] P 1fe6a521c1804962aa6db14ed3e0eb34: FlushDeltaMemStoresOp(e146f4cac25e43e8aaf1749f1bd43ae5) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4065,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:34.540809 22652 maintenance_manager.cc:419] P 1fe6a521c1804962aa6db14ed3e0eb34: Scheduling MajorDeltaCompactionOp(e146f4cac25e43e8aaf1749f1bd43ae5): perf score=1.000000
I20260812 06:20:34.680377 22582 maintenance_manager.cc:643] P 1fe6a521c1804962aa6db14ed3e0eb34: MajorDeltaCompactionOp(e146f4cac25e43e8aaf1749f1bd43ae5) complete. Timing: real 0.139s	user 0.102s	sys 0.033s 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":698,"lbm_read_time_us":8969,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27234,"lbm_writes_lt_1ms":443,"mutex_wait_us":22,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":15616,"update_count":2000}
I20260812 06:20:34.681197 22652 maintenance_manager.cc:419] P 1fe6a521c1804962aa6db14ed3e0eb34: Scheduling FlushDeltaMemStoresOp(e146f4cac25e43e8aaf1749f1bd43ae5): perf score=10.126437
I20260812 06:20:34.721385 22582 maintenance_manager.cc:643] P 1fe6a521c1804962aa6db14ed3e0eb34: FlushDeltaMemStoresOp(e146f4cac25e43e8aaf1749f1bd43ae5) complete. Timing: real 0.040s	user 0.025s	sys 0.012s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":17232,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:34.721930 22652 maintenance_manager.cc:419] P 1fe6a521c1804962aa6db14ed3e0eb34: Scheduling MajorDeltaCompactionOp(e146f4cac25e43e8aaf1749f1bd43ae5): perf score=1.000000
I20260812 06:20:34.830952 22582 maintenance_manager.cc:643] P 1fe6a521c1804962aa6db14ed3e0eb34: MajorDeltaCompactionOp(e146f4cac25e43e8aaf1749f1bd43ae5) complete. Timing: real 0.109s	user 0.089s	sys 0.019s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16569748,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":201,"lbm_read_time_us":6084,"lbm_reads_lt_1ms":363,"lbm_write_time_us":20313,"lbm_writes_lt_1ms":343,"mutex_wait_us":62,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":10368,"update_count":1500}
I20260812 06:20:34.831671 22652 maintenance_manager.cc:419] P 1fe6a521c1804962aa6db14ed3e0eb34: Scheduling FlushDeltaMemStoresOp(e146f4cac25e43e8aaf1749f1bd43ae5): perf score=10.126437
I20260812 06:20:34.870615 22582 maintenance_manager.cc:643] P 1fe6a521c1804962aa6db14ed3e0eb34: FlushDeltaMemStoresOp(e146f4cac25e43e8aaf1749f1bd43ae5) complete. Timing: real 0.039s	user 0.030s	sys 0.004s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":15923,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:34.871415 22652 maintenance_manager.cc:419] P 1fe6a521c1804962aa6db14ed3e0eb34: Scheduling FlushDeltaMemStoresOp(e146f4cac25e43e8aaf1749f1bd43ae5): perf score=2.188937
I20260812 06:20:34.887060 22582 maintenance_manager.cc:643] P 1fe6a521c1804962aa6db14ed3e0eb34: FlushDeltaMemStoresOp(e146f4cac25e43e8aaf1749f1bd43ae5) complete. Timing: real 0.015s	user 0.015s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5612,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:34.887751 22652 maintenance_manager.cc:419] P 1fe6a521c1804962aa6db14ed3e0eb34: Scheduling MajorDeltaCompactionOp(e146f4cac25e43e8aaf1749f1bd43ae5): perf score=1.000000
I20260812 06:20:35.034924 22582 maintenance_manager.cc:643] P 1fe6a521c1804962aa6db14ed3e0eb34: MajorDeltaCompactionOp(e146f4cac25e43e8aaf1749f1bd43ae5) complete. Timing: real 0.147s	user 0.106s	sys 0.036s 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":1120,"lbm_read_time_us":8353,"lbm_reads_lt_1ms":472,"lbm_write_time_us":29349,"lbm_writes_lt_1ms":443,"mutex_wait_us":31,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4480,"update_count":2000}
I20260812 06:20:35.035693 22652 maintenance_manager.cc:419] P 1fe6a521c1804962aa6db14ed3e0eb34: Scheduling FlushDeltaMemStoresOp(e146f4cac25e43e8aaf1749f1bd43ae5): perf score=10.126437
I20260812 06:20:35.086184 22582 maintenance_manager.cc:643] P 1fe6a521c1804962aa6db14ed3e0eb34: FlushDeltaMemStoresOp(e146f4cac25e43e8aaf1749f1bd43ae5) complete. Timing: real 0.050s	user 0.028s	sys 0.008s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":16846,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:35.086881 22652 maintenance_manager.cc:419] P 1fe6a521c1804962aa6db14ed3e0eb34: Scheduling FlushDeltaMemStoresOp(e146f4cac25e43e8aaf1749f1bd43ae5): perf score=2.188937
I20260812 06:20:35.098869 22582 maintenance_manager.cc:643] P 1fe6a521c1804962aa6db14ed3e0eb34: FlushDeltaMemStoresOp(e146f4cac25e43e8aaf1749f1bd43ae5) complete. Timing: real 0.012s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4603,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:35.099376 22652 maintenance_manager.cc:419] P 1fe6a521c1804962aa6db14ed3e0eb34: Scheduling MajorDeltaCompactionOp(e146f4cac25e43e8aaf1749f1bd43ae5): perf score=1.000000
I20260812 06:20:35.240970 22582 maintenance_manager.cc:643] P 1fe6a521c1804962aa6db14ed3e0eb34: MajorDeltaCompactionOp(e146f4cac25e43e8aaf1749f1bd43ae5) complete. Timing: real 0.141s	user 0.113s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":255,"lbm_read_time_us":9385,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26806,"lbm_writes_lt_1ms":443,"mutex_wait_us":145,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":85248,"update_count":2000}
I20260812 06:20:35.244796 22652 maintenance_manager.cc:419] P 1fe6a521c1804962aa6db14ed3e0eb34: Scheduling FlushDeltaMemStoresOp(e146f4cac25e43e8aaf1749f1bd43ae5): perf score=10.126437
I20260812 06:20:35.285477 22582 maintenance_manager.cc:643] P 1fe6a521c1804962aa6db14ed3e0eb34: FlushDeltaMemStoresOp(e146f4cac25e43e8aaf1749f1bd43ae5) complete. Timing: real 0.040s	user 0.029s	sys 0.008s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17917,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:35.286038 22652 maintenance_manager.cc:419] P 1fe6a521c1804962aa6db14ed3e0eb34: Scheduling FlushDeltaMemStoresOp(e146f4cac25e43e8aaf1749f1bd43ae5): perf score=2.188937
I20260812 06:20:35.300092 22582 maintenance_manager.cc:643] P 1fe6a521c1804962aa6db14ed3e0eb34: FlushDeltaMemStoresOp(e146f4cac25e43e8aaf1749f1bd43ae5) complete. Timing: real 0.014s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5269,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:35.300575 22652 maintenance_manager.cc:419] P 1fe6a521c1804962aa6db14ed3e0eb34: Scheduling MajorDeltaCompactionOp(e146f4cac25e43e8aaf1749f1bd43ae5): perf score=1.000000
I20260812 06:20:35.424803 22582 maintenance_manager.cc:643] P 1fe6a521c1804962aa6db14ed3e0eb34: MajorDeltaCompactionOp(e146f4cac25e43e8aaf1749f1bd43ae5) complete. Timing: real 0.124s	user 0.108s	sys 0.016s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":258,"lbm_read_time_us":8230,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24210,"lbm_writes_lt_1ms":443,"mutex_wait_us":24,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":17152,"update_count":2000}
I20260812 06:20:35.425335 22652 maintenance_manager.cc:419] P 1fe6a521c1804962aa6db14ed3e0eb34: Scheduling FlushDeltaMemStoresOp(e146f4cac25e43e8aaf1749f1bd43ae5): perf score=10.126437
I20260812 06:20:35.478924 22582 maintenance_manager.cc:643] P 1fe6a521c1804962aa6db14ed3e0eb34: FlushDeltaMemStoresOp(e146f4cac25e43e8aaf1749f1bd43ae5) complete. Timing: real 0.053s	user 0.029s	sys 0.022s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18932,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:20:35.479589 22652 maintenance_manager.cc:419] P 1fe6a521c1804962aa6db14ed3e0eb34: Scheduling FlushDeltaMemStoresOp(e146f4cac25e43e8aaf1749f1bd43ae5): perf score=2.188937
I20260812 06:20:35.491314 22582 maintenance_manager.cc:643] P 1fe6a521c1804962aa6db14ed3e0eb34: FlushDeltaMemStoresOp(e146f4cac25e43e8aaf1749f1bd43ae5) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4346,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:35.491813 22652 maintenance_manager.cc:419] P 1fe6a521c1804962aa6db14ed3e0eb34: Scheduling MajorDeltaCompactionOp(e146f4cac25e43e8aaf1749f1bd43ae5): perf score=1.000000
I20260812 06:20:35.655630 22582 maintenance_manager.cc:643] P 1fe6a521c1804962aa6db14ed3e0eb34: MajorDeltaCompactionOp(e146f4cac25e43e8aaf1749f1bd43ae5) complete. Timing: real 0.164s	user 0.119s	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":664,"lbm_read_time_us":11810,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25934,"lbm_writes_lt_1ms":443,"mutex_wait_us":54,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2432,"update_count":2000}
I20260812 06:20:35.656318 22652 maintenance_manager.cc:419] P 1fe6a521c1804962aa6db14ed3e0eb34: Scheduling FlushDeltaMemStoresOp(e146f4cac25e43e8aaf1749f1bd43ae5): perf score=10.126437
I20260812 06:20:35.705818 22582 maintenance_manager.cc:643] P 1fe6a521c1804962aa6db14ed3e0eb34: FlushDeltaMemStoresOp(e146f4cac25e43e8aaf1749f1bd43ae5) complete. Timing: real 0.049s	user 0.024s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17134,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:35.706403 22652 maintenance_manager.cc:419] P 1fe6a521c1804962aa6db14ed3e0eb34: Scheduling FlushDeltaMemStoresOp(e146f4cac25e43e8aaf1749f1bd43ae5): perf score=2.188937
I20260812 06:20:35.718358 22582 maintenance_manager.cc:643] P 1fe6a521c1804962aa6db14ed3e0eb34: FlushDeltaMemStoresOp(e146f4cac25e43e8aaf1749f1bd43ae5) complete. Timing: real 0.012s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4487,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:35.718943 22652 maintenance_manager.cc:419] P 1fe6a521c1804962aa6db14ed3e0eb34: Scheduling FlushMRSOp(e146f4cac25e43e8aaf1749f1bd43ae5): perf score=1.000000
I20260812 06:20:35.746033 22582 maintenance_manager.cc:643] P 1fe6a521c1804962aa6db14ed3e0eb34: FlushMRSOp(e146f4cac25e43e8aaf1749f1bd43ae5) complete. Timing: real 0.027s	user 0.025s	sys 0.000s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":73,"dirs.run_cpu_time_us":227,"dirs.run_wall_time_us":1712,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1632,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:20:35.746766 22652 maintenance_manager.cc:419] P 1fe6a521c1804962aa6db14ed3e0eb34: Scheduling LogGCOp(e146f4cac25e43e8aaf1749f1bd43ae5): free 124710296 bytes of WAL
I20260812 06:20:35.747032 22582 log_reader.cc:385] T e146f4cac25e43e8aaf1749f1bd43ae5: removed 12 log segments from log reader
I20260812 06:20:35.747105 22582 log.cc:1079] T e146f4cac25e43e8aaf1749f1bd43ae5 P 1fe6a521c1804962aa6db14ed3e0eb34: Deleting log segment in path: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515627637820-22236-0/minicluster-data/ts-0-root/wals/e146f4cac25e43e8aaf1749f1bd43ae5/wal-000000003 (ops 12-16)
I20260812 06:20:35.747143 22582 log.cc:1079] T e146f4cac25e43e8aaf1749f1bd43ae5 P 1fe6a521c1804962aa6db14ed3e0eb34: Deleting log segment in path: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515627637820-22236-0/minicluster-data/ts-0-root/wals/e146f4cac25e43e8aaf1749f1bd43ae5/wal-000000004 (ops 17-21)
I20260812 06:20:35.747167 22582 log.cc:1079] T e146f4cac25e43e8aaf1749f1bd43ae5 P 1fe6a521c1804962aa6db14ed3e0eb34: Deleting log segment in path: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515627637820-22236-0/minicluster-data/ts-0-root/wals/e146f4cac25e43e8aaf1749f1bd43ae5/wal-000000005 (ops 22-26)
I20260812 06:20:35.747191 22582 log.cc:1079] T e146f4cac25e43e8aaf1749f1bd43ae5 P 1fe6a521c1804962aa6db14ed3e0eb34: Deleting log segment in path: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515627637820-22236-0/minicluster-data/ts-0-root/wals/e146f4cac25e43e8aaf1749f1bd43ae5/wal-000000006 (ops 27-31)
I20260812 06:20:35.747218 22582 log.cc:1079] T e146f4cac25e43e8aaf1749f1bd43ae5 P 1fe6a521c1804962aa6db14ed3e0eb34: Deleting log segment in path: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515627637820-22236-0/minicluster-data/ts-0-root/wals/e146f4cac25e43e8aaf1749f1bd43ae5/wal-000000007 (ops 32-36)
I20260812 06:20:35.747254 22582 log.cc:1079] T e146f4cac25e43e8aaf1749f1bd43ae5 P 1fe6a521c1804962aa6db14ed3e0eb34: Deleting log segment in path: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515627637820-22236-0/minicluster-data/ts-0-root/wals/e146f4cac25e43e8aaf1749f1bd43ae5/wal-000000008 (ops 37-41)
I20260812 06:20:35.747283 22582 log.cc:1079] T e146f4cac25e43e8aaf1749f1bd43ae5 P 1fe6a521c1804962aa6db14ed3e0eb34: Deleting log segment in path: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515627637820-22236-0/minicluster-data/ts-0-root/wals/e146f4cac25e43e8aaf1749f1bd43ae5/wal-000000009 (ops 42-46)
I20260812 06:20:35.747308 22582 log.cc:1079] T e146f4cac25e43e8aaf1749f1bd43ae5 P 1fe6a521c1804962aa6db14ed3e0eb34: Deleting log segment in path: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515627637820-22236-0/minicluster-data/ts-0-root/wals/e146f4cac25e43e8aaf1749f1bd43ae5/wal-000000010 (ops 47-51)
I20260812 06:20:35.747339 22582 log.cc:1079] T e146f4cac25e43e8aaf1749f1bd43ae5 P 1fe6a521c1804962aa6db14ed3e0eb34: Deleting log segment in path: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515627637820-22236-0/minicluster-data/ts-0-root/wals/e146f4cac25e43e8aaf1749f1bd43ae5/wal-000000011 (ops 52-56)
I20260812 06:20:35.747364 22582 log.cc:1079] T e146f4cac25e43e8aaf1749f1bd43ae5 P 1fe6a521c1804962aa6db14ed3e0eb34: Deleting log segment in path: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515627637820-22236-0/minicluster-data/ts-0-root/wals/e146f4cac25e43e8aaf1749f1bd43ae5/wal-000000012 (ops 57-61)
I20260812 06:20:35.747398 22582 log.cc:1079] T e146f4cac25e43e8aaf1749f1bd43ae5 P 1fe6a521c1804962aa6db14ed3e0eb34: Deleting log segment in path: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515627637820-22236-0/minicluster-data/ts-0-root/wals/e146f4cac25e43e8aaf1749f1bd43ae5/wal-000000013 (ops 62-66)
I20260812 06:20:35.747430 22582 log.cc:1079] T e146f4cac25e43e8aaf1749f1bd43ae5 P 1fe6a521c1804962aa6db14ed3e0eb34: Deleting log segment in path: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515627637820-22236-0/minicluster-data/ts-0-root/wals/e146f4cac25e43e8aaf1749f1bd43ae5/wal-000000014 (ops 67-71)
I20260812 06:20:35.777160 22582 maintenance_manager.cc:643] P 1fe6a521c1804962aa6db14ed3e0eb34: LogGCOp(e146f4cac25e43e8aaf1749f1bd43ae5) complete. Timing: real 0.030s	user 0.000s	sys 0.028s Metrics: {}
I20260812 06:20:35.777540 22652 maintenance_manager.cc:419] P 1fe6a521c1804962aa6db14ed3e0eb34: Scheduling UndoDeltaBlockGCOp(e146f4cac25e43e8aaf1749f1bd43ae5): 472 bytes on disk
I20260812 06:20:35.777971 22582 maintenance_manager.cc:643] P 1fe6a521c1804962aa6db14ed3e0eb34: UndoDeltaBlockGCOp(e146f4cac25e43e8aaf1749f1bd43ae5) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4}
I20260812 06:20:35.778427 22652 maintenance_manager.cc:419] P 1fe6a521c1804962aa6db14ed3e0eb34: Scheduling FlushDeltaMemStoresOp(e146f4cac25e43e8aaf1749f1bd43ae5): perf score=2.188937
I20260812 06:20:35.807847 22582 maintenance_manager.cc:643] P 1fe6a521c1804962aa6db14ed3e0eb34: FlushDeltaMemStoresOp(e146f4cac25e43e8aaf1749f1bd43ae5) complete. Timing: real 0.029s	user 0.010s	sys 0.013s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6338,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:35.808488 22652 maintenance_manager.cc:419] P 1fe6a521c1804962aa6db14ed3e0eb34: Scheduling FlushDeltaMemStoresOp(e146f4cac25e43e8aaf1749f1bd43ae5): perf score=2.188937
I20260812 06:20:35.821553 22582 maintenance_manager.cc:643] P 1fe6a521c1804962aa6db14ed3e0eb34: FlushDeltaMemStoresOp(e146f4cac25e43e8aaf1749f1bd43ae5) complete. Timing: real 0.013s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5958,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":102,"reinsert_count":0,"update_count":500}
I20260812 06:20:35.822109 22652 maintenance_manager.cc:419] P 1fe6a521c1804962aa6db14ed3e0eb34: Scheduling MajorDeltaCompactionOp(e146f4cac25e43e8aaf1749f1bd43ae5): perf score=1.000000
I20260812 06:20:36.039057 22582 maintenance_manager.cc:643] P 1fe6a521c1804962aa6db14ed3e0eb34: MajorDeltaCompactionOp(e146f4cac25e43e8aaf1749f1bd43ae5) complete. Timing: real 0.217s	user 0.152s	sys 0.064s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877338,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":823,"lbm_read_time_us":15121,"lbm_reads_lt_1ms":674,"lbm_write_time_us":37477,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":19840,"thread_start_us":97,"threads_started":1,"update_count":3000}
I20260812 06:20:36.039844 22652 maintenance_manager.cc:419] P 1fe6a521c1804962aa6db14ed3e0eb34: Scheduling FlushDeltaMemStoresOp(e146f4cac25e43e8aaf1749f1bd43ae5): perf score=14.095187
I20260812 06:20:36.097925 22582 maintenance_manager.cc:643] P 1fe6a521c1804962aa6db14ed3e0eb34: FlushDeltaMemStoresOp(e146f4cac25e43e8aaf1749f1bd43ae5) complete. Timing: real 0.058s	user 0.031s	sys 0.023s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20511,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:36.098513 22652 maintenance_manager.cc:419] P 1fe6a521c1804962aa6db14ed3e0eb34: Scheduling FlushDeltaMemStoresOp(e146f4cac25e43e8aaf1749f1bd43ae5): perf score=2.188937
I20260812 06:20:36.109644 22582 maintenance_manager.cc:643] P 1fe6a521c1804962aa6db14ed3e0eb34: FlushDeltaMemStoresOp(e146f4cac25e43e8aaf1749f1bd43ae5) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4338,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:36.110330 22652 maintenance_manager.cc:419] P 1fe6a521c1804962aa6db14ed3e0eb34: Scheduling MajorDeltaCompactionOp(e146f4cac25e43e8aaf1749f1bd43ae5): perf score=1.000000
I20260812 06:20:36.311259 22582 maintenance_manager.cc:643] P 1fe6a521c1804962aa6db14ed3e0eb34: MajorDeltaCompactionOp(e146f4cac25e43e8aaf1749f1bd43ae5) complete. Timing: real 0.201s	user 0.121s	sys 0.069s 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":803,"lbm_read_time_us":14231,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30831,"lbm_writes_lt_1ms":543,"mutex_wait_us":365,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14080,"update_count":2500}
I20260812 06:20:36.312352 22652 maintenance_manager.cc:419] P 1fe6a521c1804962aa6db14ed3e0eb34: Scheduling FlushDeltaMemStoresOp(e146f4cac25e43e8aaf1749f1bd43ae5): perf score=14.095187
I20260812 06:20:36.367974 22582 maintenance_manager.cc:643] P 1fe6a521c1804962aa6db14ed3e0eb34: FlushDeltaMemStoresOp(e146f4cac25e43e8aaf1749f1bd43ae5) complete. Timing: real 0.055s	user 0.038s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24467,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:36.368571 22652 maintenance_manager.cc:419] P 1fe6a521c1804962aa6db14ed3e0eb34: Scheduling FlushDeltaMemStoresOp(e146f4cac25e43e8aaf1749f1bd43ae5): perf score=2.188937
I20260812 06:20:36.394337 22582 maintenance_manager.cc:643] P 1fe6a521c1804962aa6db14ed3e0eb34: FlushDeltaMemStoresOp(e146f4cac25e43e8aaf1749f1bd43ae5) complete. Timing: real 0.026s	user 0.015s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6033,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:36.395021 22652 maintenance_manager.cc:419] P 1fe6a521c1804962aa6db14ed3e0eb34: Scheduling MajorDeltaCompactionOp(e146f4cac25e43e8aaf1749f1bd43ae5): perf score=1.000000
I20260812 06:20:36.592746 22582 maintenance_manager.cc:643] P 1fe6a521c1804962aa6db14ed3e0eb34: MajorDeltaCompactionOp(e146f4cac25e43e8aaf1749f1bd43ae5) complete. Timing: real 0.197s	user 0.133s	sys 0.063s 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":500,"lbm_read_time_us":14193,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31930,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10496,"update_count":2500}
I20260812 06:20:36.593509 22652 maintenance_manager.cc:419] P 1fe6a521c1804962aa6db14ed3e0eb34: Scheduling FlushDeltaMemStoresOp(e146f4cac25e43e8aaf1749f1bd43ae5): perf score=14.095187
I20260812 06:20:36.651185 22582 maintenance_manager.cc:643] P 1fe6a521c1804962aa6db14ed3e0eb34: FlushDeltaMemStoresOp(e146f4cac25e43e8aaf1749f1bd43ae5) complete. Timing: real 0.057s	user 0.045s	sys 0.012s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":25167,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:36.652045 22652 maintenance_manager.cc:419] P 1fe6a521c1804962aa6db14ed3e0eb34: Scheduling FlushDeltaMemStoresOp(e146f4cac25e43e8aaf1749f1bd43ae5): perf score=2.188937
I20260812 06:20:36.667225 22582 maintenance_manager.cc:643] P 1fe6a521c1804962aa6db14ed3e0eb34: FlushDeltaMemStoresOp(e146f4cac25e43e8aaf1749f1bd43ae5) complete. Timing: real 0.015s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4503,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:36.667804 22652 maintenance_manager.cc:419] P 1fe6a521c1804962aa6db14ed3e0eb34: Scheduling MajorDeltaCompactionOp(e146f4cac25e43e8aaf1749f1bd43ae5): perf score=1.000000
I20260812 06:20:36.852861 22582 maintenance_manager.cc:643] P 1fe6a521c1804962aa6db14ed3e0eb34: MajorDeltaCompactionOp(e146f4cac25e43e8aaf1749f1bd43ae5) complete. Timing: real 0.185s	user 0.130s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":760,"lbm_read_time_us":11028,"lbm_reads_lt_1ms":564,"lbm_write_time_us":29772,"lbm_writes_lt_1ms":543,"mutex_wait_us":285,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4992,"update_count":2500}
I20260812 06:20:36.853494 22652 maintenance_manager.cc:419] P 1fe6a521c1804962aa6db14ed3e0eb34: Scheduling FlushDeltaMemStoresOp(e146f4cac25e43e8aaf1749f1bd43ae5): perf score=14.095187
I20260812 06:20:36.915958 22582 maintenance_manager.cc:643] P 1fe6a521c1804962aa6db14ed3e0eb34: FlushDeltaMemStoresOp(e146f4cac25e43e8aaf1749f1bd43ae5) complete. Timing: real 0.062s	user 0.037s	sys 0.023s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":27843,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:36.916656 22652 maintenance_manager.cc:419] P 1fe6a521c1804962aa6db14ed3e0eb34: Scheduling FlushDeltaMemStoresOp(e146f4cac25e43e8aaf1749f1bd43ae5): perf score=2.188937
I20260812 06:20:36.939572 22582 maintenance_manager.cc:643] P 1fe6a521c1804962aa6db14ed3e0eb34: FlushDeltaMemStoresOp(e146f4cac25e43e8aaf1749f1bd43ae5) complete. Timing: real 0.023s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5832,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:36.940326 22652 maintenance_manager.cc:419] P 1fe6a521c1804962aa6db14ed3e0eb34: Scheduling MajorDeltaCompactionOp(e146f4cac25e43e8aaf1749f1bd43ae5): perf score=1.000000
I20260812 06:20:37.103901 22582 maintenance_manager.cc:643] P 1fe6a521c1804962aa6db14ed3e0eb34: MajorDeltaCompactionOp(e146f4cac25e43e8aaf1749f1bd43ae5) complete. Timing: real 0.163s	user 0.128s	sys 0.034s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":271,"lbm_read_time_us":9883,"lbm_reads_lt_1ms":564,"lbm_write_time_us":32190,"lbm_writes_lt_1ms":543,"mutex_wait_us":62,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9728,"update_count":2500}
I20260812 06:20:37.104694 22652 maintenance_manager.cc:419] P 1fe6a521c1804962aa6db14ed3e0eb34: Scheduling FlushDeltaMemStoresOp(e146f4cac25e43e8aaf1749f1bd43ae5): perf score=14.095187
I20260812 06:20:37.172219 22582 maintenance_manager.cc:643] P 1fe6a521c1804962aa6db14ed3e0eb34: FlushDeltaMemStoresOp(e146f4cac25e43e8aaf1749f1bd43ae5) complete. Timing: real 0.067s	user 0.029s	sys 0.036s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":30919,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:37.172796 22652 maintenance_manager.cc:419] P 1fe6a521c1804962aa6db14ed3e0eb34: Scheduling FlushDeltaMemStoresOp(e146f4cac25e43e8aaf1749f1bd43ae5): perf score=2.188937
I20260812 06:20:37.191026 22582 maintenance_manager.cc:643] P 1fe6a521c1804962aa6db14ed3e0eb34: FlushDeltaMemStoresOp(e146f4cac25e43e8aaf1749f1bd43ae5) complete. Timing: real 0.018s	user 0.017s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6804,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:37.192068 22652 maintenance_manager.cc:419] P 1fe6a521c1804962aa6db14ed3e0eb34: Scheduling MajorDeltaCompactionOp(e146f4cac25e43e8aaf1749f1bd43ae5): perf score=1.000000
I20260812 06:20:37.355893 22582 maintenance_manager.cc:643] P 1fe6a521c1804962aa6db14ed3e0eb34: MajorDeltaCompactionOp(e146f4cac25e43e8aaf1749f1bd43ae5) complete. Timing: real 0.164s	user 0.121s	sys 0.036s 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":1848,"lbm_read_time_us":11127,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31619,"lbm_writes_lt_1ms":543,"mutex_wait_us":588,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":2500}
I20260812 06:20:37.356899 22652 maintenance_manager.cc:419] P 1fe6a521c1804962aa6db14ed3e0eb34: Scheduling FlushDeltaMemStoresOp(e146f4cac25e43e8aaf1749f1bd43ae5): perf score=14.095187
I20260812 06:20:37.407454 22582 maintenance_manager.cc:643] P 1fe6a521c1804962aa6db14ed3e0eb34: FlushDeltaMemStoresOp(e146f4cac25e43e8aaf1749f1bd43ae5) complete. Timing: real 0.050s	user 0.043s	sys 0.003s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":20355,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:37.408090 22652 maintenance_manager.cc:419] P 1fe6a521c1804962aa6db14ed3e0eb34: Scheduling FlushDeltaMemStoresOp(e146f4cac25e43e8aaf1749f1bd43ae5): perf score=2.188937
I20260812 06:20:37.421228 22582 maintenance_manager.cc:643] P 1fe6a521c1804962aa6db14ed3e0eb34: FlushDeltaMemStoresOp(e146f4cac25e43e8aaf1749f1bd43ae5) complete. Timing: real 0.013s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4763,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:37.421900 22652 maintenance_manager.cc:419] P 1fe6a521c1804962aa6db14ed3e0eb34: Scheduling FlushMRSOp(e146f4cac25e43e8aaf1749f1bd43ae5): perf score=1.000000
I20260812 06:20:37.458995 22582 maintenance_manager.cc:643] P 1fe6a521c1804962aa6db14ed3e0eb34: FlushMRSOp(e146f4cac25e43e8aaf1749f1bd43ae5) complete. Timing: real 0.037s	user 0.033s	sys 0.003s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":74,"dirs.run_cpu_time_us":288,"dirs.run_wall_time_us":1671,"drs_written":1,"lbm_read_time_us":102,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2219,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:20:37.459791 22652 maintenance_manager.cc:419] P 1fe6a521c1804962aa6db14ed3e0eb34: Scheduling LogGCOp(e146f4cac25e43e8aaf1749f1bd43ae5): free 124710258 bytes of WAL
I20260812 06:20:37.460012 22582 log_reader.cc:385] T e146f4cac25e43e8aaf1749f1bd43ae5: removed 12 log segments from log reader
I20260812 06:20:37.460058 22582 log.cc:1079] T e146f4cac25e43e8aaf1749f1bd43ae5 P 1fe6a521c1804962aa6db14ed3e0eb34: Deleting log segment in path: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515627637820-22236-0/minicluster-data/ts-0-root/wals/e146f4cac25e43e8aaf1749f1bd43ae5/wal-000000015 (ops 72-76)
I20260812 06:20:37.460088 22582 log.cc:1079] T e146f4cac25e43e8aaf1749f1bd43ae5 P 1fe6a521c1804962aa6db14ed3e0eb34: Deleting log segment in path: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515627637820-22236-0/minicluster-data/ts-0-root/wals/e146f4cac25e43e8aaf1749f1bd43ae5/wal-000000016 (ops 77-81)
I20260812 06:20:37.460158 22582 log.cc:1079] T e146f4cac25e43e8aaf1749f1bd43ae5 P 1fe6a521c1804962aa6db14ed3e0eb34: Deleting log segment in path: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515627637820-22236-0/minicluster-data/ts-0-root/wals/e146f4cac25e43e8aaf1749f1bd43ae5/wal-000000017 (ops 82-86)
I20260812 06:20:37.460209 22582 log.cc:1079] T e146f4cac25e43e8aaf1749f1bd43ae5 P 1fe6a521c1804962aa6db14ed3e0eb34: Deleting log segment in path: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515627637820-22236-0/minicluster-data/ts-0-root/wals/e146f4cac25e43e8aaf1749f1bd43ae5/wal-000000018 (ops 87-91)
I20260812 06:20:37.460249 22582 log.cc:1079] T e146f4cac25e43e8aaf1749f1bd43ae5 P 1fe6a521c1804962aa6db14ed3e0eb34: Deleting log segment in path: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515627637820-22236-0/minicluster-data/ts-0-root/wals/e146f4cac25e43e8aaf1749f1bd43ae5/wal-000000019 (ops 92-96)
I20260812 06:20:37.460291 22582 log.cc:1079] T e146f4cac25e43e8aaf1749f1bd43ae5 P 1fe6a521c1804962aa6db14ed3e0eb34: Deleting log segment in path: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515627637820-22236-0/minicluster-data/ts-0-root/wals/e146f4cac25e43e8aaf1749f1bd43ae5/wal-000000020 (ops 97-101)
I20260812 06:20:37.460330 22582 log.cc:1079] T e146f4cac25e43e8aaf1749f1bd43ae5 P 1fe6a521c1804962aa6db14ed3e0eb34: Deleting log segment in path: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515627637820-22236-0/minicluster-data/ts-0-root/wals/e146f4cac25e43e8aaf1749f1bd43ae5/wal-000000021 (ops 102-106)
I20260812 06:20:37.460369 22582 log.cc:1079] T e146f4cac25e43e8aaf1749f1bd43ae5 P 1fe6a521c1804962aa6db14ed3e0eb34: Deleting log segment in path: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515627637820-22236-0/minicluster-data/ts-0-root/wals/e146f4cac25e43e8aaf1749f1bd43ae5/wal-000000022 (ops 107-111)
I20260812 06:20:37.460408 22582 log.cc:1079] T e146f4cac25e43e8aaf1749f1bd43ae5 P 1fe6a521c1804962aa6db14ed3e0eb34: Deleting log segment in path: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515627637820-22236-0/minicluster-data/ts-0-root/wals/e146f4cac25e43e8aaf1749f1bd43ae5/wal-000000023 (ops 112-116)
I20260812 06:20:37.460448 22582 log.cc:1079] T e146f4cac25e43e8aaf1749f1bd43ae5 P 1fe6a521c1804962aa6db14ed3e0eb34: Deleting log segment in path: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515627637820-22236-0/minicluster-data/ts-0-root/wals/e146f4cac25e43e8aaf1749f1bd43ae5/wal-000000024 (ops 117-121)
I20260812 06:20:37.460486 22582 log.cc:1079] T e146f4cac25e43e8aaf1749f1bd43ae5 P 1fe6a521c1804962aa6db14ed3e0eb34: Deleting log segment in path: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515627637820-22236-0/minicluster-data/ts-0-root/wals/e146f4cac25e43e8aaf1749f1bd43ae5/wal-000000025 (ops 122-126)
I20260812 06:20:37.460528 22582 log.cc:1079] T e146f4cac25e43e8aaf1749f1bd43ae5 P 1fe6a521c1804962aa6db14ed3e0eb34: Deleting log segment in path: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515627637820-22236-0/minicluster-data/ts-0-root/wals/e146f4cac25e43e8aaf1749f1bd43ae5/wal-000000026 (ops 127-131)
I20260812 06:20:37.491551 22582 maintenance_manager.cc:643] P 1fe6a521c1804962aa6db14ed3e0eb34: LogGCOp(e146f4cac25e43e8aaf1749f1bd43ae5) complete. Timing: real 0.032s	user 0.000s	sys 0.031s Metrics: {}
I20260812 06:20:37.492091 22652 maintenance_manager.cc:419] P 1fe6a521c1804962aa6db14ed3e0eb34: Scheduling UndoDeltaBlockGCOp(e146f4cac25e43e8aaf1749f1bd43ae5): 493 bytes on disk
I20260812 06:20:37.492677 22582 maintenance_manager.cc:643] P 1fe6a521c1804962aa6db14ed3e0eb34: UndoDeltaBlockGCOp(e146f4cac25e43e8aaf1749f1bd43ae5) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4}
I20260812 06:20:37.493276 22652 maintenance_manager.cc:419] P 1fe6a521c1804962aa6db14ed3e0eb34: Scheduling FlushDeltaMemStoresOp(e146f4cac25e43e8aaf1749f1bd43ae5): perf score=3.181125
I20260812 06:20:37.508244 22582 maintenance_manager.cc:643] P 1fe6a521c1804962aa6db14ed3e0eb34: FlushDeltaMemStoresOp(e146f4cac25e43e8aaf1749f1bd43ae5) complete. Timing: real 0.015s	user 0.009s	sys 0.004s Metrics: {"bytes_written":5046217,"delete_count":0,"lbm_write_time_us":5876,"lbm_writes_lt_1ms":126,"reinsert_count":0,"update_count":615}
I20260812 06:20:37.508839 22652 maintenance_manager.cc:419] P 1fe6a521c1804962aa6db14ed3e0eb34: Scheduling LogGCOp(e146f4cac25e43e8aaf1749f1bd43ae5): free 12018006 bytes of WAL
I20260812 06:20:37.509110 22582 log_reader.cc:385] T e146f4cac25e43e8aaf1749f1bd43ae5: removed 1 log segments from log reader
I20260812 06:20:37.509177 22582 log.cc:1079] T e146f4cac25e43e8aaf1749f1bd43ae5 P 1fe6a521c1804962aa6db14ed3e0eb34: Deleting log segment in path: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515627637820-22236-0/minicluster-data/ts-0-root/wals/e146f4cac25e43e8aaf1749f1bd43ae5/wal-000000027 (ops 132-136)
I20260812 06:20:37.512236 22582 maintenance_manager.cc:643] P 1fe6a521c1804962aa6db14ed3e0eb34: LogGCOp(e146f4cac25e43e8aaf1749f1bd43ae5) complete. Timing: real 0.003s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:20:37.512833 22652 maintenance_manager.cc:419] P 1fe6a521c1804962aa6db14ed3e0eb34: Scheduling FlushDeltaMemStoresOp(e146f4cac25e43e8aaf1749f1bd43ae5): perf score=1.196750
I20260812 06:20:37.527379 22582 maintenance_manager.cc:643] P 1fe6a521c1804962aa6db14ed3e0eb34: FlushDeltaMemStoresOp(e146f4cac25e43e8aaf1749f1bd43ae5) complete. Timing: real 0.014s	user 0.008s	sys 0.005s Metrics: {"bytes_written":3159080,"delete_count":0,"lbm_write_time_us":5198,"lbm_writes_lt_1ms":80,"reinsert_count":0,"update_count":385}
I20260812 06:20:37.528029 22652 maintenance_manager.cc:419] P 1fe6a521c1804962aa6db14ed3e0eb34: Scheduling MajorDeltaCompactionOp(e146f4cac25e43e8aaf1749f1bd43ae5): perf score=1.000000
I20260812 06:20:37.780483 22582 maintenance_manager.cc:643] P 1fe6a521c1804962aa6db14ed3e0eb34: MajorDeltaCompactionOp(e146f4cac25e43e8aaf1749f1bd43ae5) complete. Timing: real 0.252s	user 0.156s	sys 0.082s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979732,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1394,"lbm_read_time_us":16097,"lbm_reads_lt_1ms":766,"lbm_write_time_us":41331,"lbm_writes_lt_1ms":743,"mutex_wait_us":316,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":40192,"thread_start_us":101,"threads_started":1,"update_count":3500}
I20260812 06:20:37.781277 22652 maintenance_manager.cc:419] P 1fe6a521c1804962aa6db14ed3e0eb34: Scheduling FlushDeltaMemStoresOp(e146f4cac25e43e8aaf1749f1bd43ae5): perf score=18.063937
I20260812 06:20:37.863775 22582 maintenance_manager.cc:643] P 1fe6a521c1804962aa6db14ed3e0eb34: FlushDeltaMemStoresOp(e146f4cac25e43e8aaf1749f1bd43ae5) complete. Timing: real 0.082s	user 0.042s	sys 0.039s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":30266,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:37.864363 22652 maintenance_manager.cc:419] P 1fe6a521c1804962aa6db14ed3e0eb34: Scheduling FlushDeltaMemStoresOp(e146f4cac25e43e8aaf1749f1bd43ae5): perf score=2.188937
I20260812 06:20:37.897317 22582 maintenance_manager.cc:643] P 1fe6a521c1804962aa6db14ed3e0eb34: FlushDeltaMemStoresOp(e146f4cac25e43e8aaf1749f1bd43ae5) complete. Timing: real 0.033s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6408,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:37.897892 22652 maintenance_manager.cc:419] P 1fe6a521c1804962aa6db14ed3e0eb34: Scheduling FlushDeltaMemStoresOp(e146f4cac25e43e8aaf1749f1bd43ae5): perf score=2.188937
I20260812 06:20:37.909874 22582 maintenance_manager.cc:643] P 1fe6a521c1804962aa6db14ed3e0eb34: FlushDeltaMemStoresOp(e146f4cac25e43e8aaf1749f1bd43ae5) complete. Timing: real 0.012s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4570,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:37.910722 22652 maintenance_manager.cc:419] P 1fe6a521c1804962aa6db14ed3e0eb34: Scheduling MajorDeltaCompactionOp(e146f4cac25e43e8aaf1749f1bd43ae5): perf score=1.000000
I20260812 06:20:38.163160 22582 maintenance_manager.cc:643] P 1fe6a521c1804962aa6db14ed3e0eb34: MajorDeltaCompactionOp(e146f4cac25e43e8aaf1749f1bd43ae5) complete. Timing: real 0.252s	user 0.153s	sys 0.098s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":32979634,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1285,"lbm_read_time_us":17241,"lbm_reads_lt_1ms":773,"lbm_write_time_us":41521,"lbm_writes_lt_1ms":743,"mutex_wait_us":410,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":16640,"update_count":3500}
I20260812 06:20:38.164047 22652 maintenance_manager.cc:419] P 1fe6a521c1804962aa6db14ed3e0eb34: Scheduling FlushDeltaMemStoresOp(e146f4cac25e43e8aaf1749f1bd43ae5): perf score=18.063937
I20260812 06:20:38.243022 22582 maintenance_manager.cc:643] P 1fe6a521c1804962aa6db14ed3e0eb34: FlushDeltaMemStoresOp(e146f4cac25e43e8aaf1749f1bd43ae5) complete. Timing: real 0.079s	user 0.046s	sys 0.021s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":31360,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:38.243603 22652 maintenance_manager.cc:419] P 1fe6a521c1804962aa6db14ed3e0eb34: Scheduling FlushDeltaMemStoresOp(e146f4cac25e43e8aaf1749f1bd43ae5): perf score=2.188937
I20260812 06:20:38.258055 22582 maintenance_manager.cc:643] P 1fe6a521c1804962aa6db14ed3e0eb34: FlushDeltaMemStoresOp(e146f4cac25e43e8aaf1749f1bd43ae5) complete. Timing: real 0.014s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4789,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:38.258975 22652 maintenance_manager.cc:419] P 1fe6a521c1804962aa6db14ed3e0eb34: Scheduling MajorDeltaCompactionOp(e146f4cac25e43e8aaf1749f1bd43ae5): perf score=1.000000
I20260812 06:20:38.487080 22582 maintenance_manager.cc:643] P 1fe6a521c1804962aa6db14ed3e0eb34: MajorDeltaCompactionOp(e146f4cac25e43e8aaf1749f1bd43ae5) complete. Timing: real 0.228s	user 0.150s	sys 0.077s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877103,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1136,"lbm_read_time_us":14925,"lbm_reads_lt_1ms":672,"lbm_write_time_us":39024,"lbm_writes_lt_1ms":643,"mutex_wait_us":297,"peak_mem_usage":75542472,"reinsert_count":0,"update_count":3000}
I20260812 06:20:38.487699 22652 maintenance_manager.cc:419] P 1fe6a521c1804962aa6db14ed3e0eb34: Scheduling FlushDeltaMemStoresOp(e146f4cac25e43e8aaf1749f1bd43ae5): perf score=15.087375
I20260812 06:20:38.546275 22582 maintenance_manager.cc:643] P 1fe6a521c1804962aa6db14ed3e0eb34: FlushDeltaMemStoresOp(e146f4cac25e43e8aaf1749f1bd43ae5) complete. Timing: real 0.058s	user 0.021s	sys 0.033s Metrics: {"bytes_written":16820143,"delete_count":0,"lbm_write_time_us":26280,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:20:38.546833 22652 maintenance_manager.cc:419] P 1fe6a521c1804962aa6db14ed3e0eb34: Scheduling FlushDeltaMemStoresOp(e146f4cac25e43e8aaf1749f1bd43ae5): perf score=2.188937
I20260812 06:20:38.559721 22582 maintenance_manager.cc:643] P 1fe6a521c1804962aa6db14ed3e0eb34: FlushDeltaMemStoresOp(e146f4cac25e43e8aaf1749f1bd43ae5) complete. Timing: real 0.013s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4833,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:38.560346 22652 maintenance_manager.cc:419] P 1fe6a521c1804962aa6db14ed3e0eb34: Scheduling FlushDeltaMemStoresOp(e146f4cac25e43e8aaf1749f1bd43ae5): perf score=2.188937
I20260812 06:20:38.573522 22582 maintenance_manager.cc:643] P 1fe6a521c1804962aa6db14ed3e0eb34: FlushDeltaMemStoresOp(e146f4cac25e43e8aaf1749f1bd43ae5) complete. Timing: real 0.013s	user 0.006s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5169,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:38.574445 22652 maintenance_manager.cc:419] P 1fe6a521c1804962aa6db14ed3e0eb34: Scheduling MajorDeltaCompactionOp(e146f4cac25e43e8aaf1749f1bd43ae5): perf score=1.000000
I20260812 06:20:38.793120 22582 maintenance_manager.cc:643] P 1fe6a521c1804962aa6db14ed3e0eb34: MajorDeltaCompactionOp(e146f4cac25e43e8aaf1749f1bd43ae5) complete. Timing: real 0.218s	user 0.135s	sys 0.083s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877207,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":249,"lbm_read_time_us":14513,"lbm_reads_lt_1ms":673,"lbm_write_time_us":36600,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":384,"update_count":3000}
I20260812 06:20:38.793701 22652 maintenance_manager.cc:419] P 1fe6a521c1804962aa6db14ed3e0eb34: Scheduling FlushDeltaMemStoresOp(e146f4cac25e43e8aaf1749f1bd43ae5): perf score=14.095187
I20260812 06:20:38.847064 22582 maintenance_manager.cc:643] P 1fe6a521c1804962aa6db14ed3e0eb34: FlushDeltaMemStoresOp(e146f4cac25e43e8aaf1749f1bd43ae5) complete. Timing: real 0.053s	user 0.035s	sys 0.017s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23621,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:38.847676 22652 maintenance_manager.cc:419] P 1fe6a521c1804962aa6db14ed3e0eb34: Scheduling FlushDeltaMemStoresOp(e146f4cac25e43e8aaf1749f1bd43ae5): perf score=2.188937
I20260812 06:20:38.864250 22582 maintenance_manager.cc:643] P 1fe6a521c1804962aa6db14ed3e0eb34: FlushDeltaMemStoresOp(e146f4cac25e43e8aaf1749f1bd43ae5) complete. Timing: real 0.016s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4928,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:38.864935 22652 maintenance_manager.cc:419] P 1fe6a521c1804962aa6db14ed3e0eb34: Scheduling MajorDeltaCompactionOp(e146f4cac25e43e8aaf1749f1bd43ae5): perf score=1.000000
I20260812 06:20:39.046727 22582 maintenance_manager.cc:643] P 1fe6a521c1804962aa6db14ed3e0eb34: MajorDeltaCompactionOp(e146f4cac25e43e8aaf1749f1bd43ae5) complete. Timing: real 0.182s	user 0.103s	sys 0.077s 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":1052,"lbm_read_time_us":12171,"lbm_reads_lt_1ms":564,"lbm_write_time_us":31898,"lbm_writes_lt_1ms":543,"mutex_wait_us":26,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":15232,"update_count":2500}
I20260812 06:20:39.047509 22652 maintenance_manager.cc:419] P 1fe6a521c1804962aa6db14ed3e0eb34: Scheduling FlushDeltaMemStoresOp(e146f4cac25e43e8aaf1749f1bd43ae5): perf score=14.095187
I20260812 06:20:39.104319 22582 maintenance_manager.cc:643] P 1fe6a521c1804962aa6db14ed3e0eb34: FlushDeltaMemStoresOp(e146f4cac25e43e8aaf1749f1bd43ae5) complete. Timing: real 0.057s	user 0.034s	sys 0.020s Metrics: {"bytes_written":16409899,"delete_count":0,"lbm_write_time_us":25448,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:39.104921 22652 maintenance_manager.cc:419] P 1fe6a521c1804962aa6db14ed3e0eb34: Scheduling FlushDeltaMemStoresOp(e146f4cac25e43e8aaf1749f1bd43ae5): perf score=2.188937
I20260812 06:20:39.120249 22582 maintenance_manager.cc:643] P 1fe6a521c1804962aa6db14ed3e0eb34: FlushDeltaMemStoresOp(e146f4cac25e43e8aaf1749f1bd43ae5) complete. Timing: real 0.015s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5990,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:39.120841 22652 maintenance_manager.cc:419] P 1fe6a521c1804962aa6db14ed3e0eb34: Scheduling FlushMRSOp(e146f4cac25e43e8aaf1749f1bd43ae5): perf score=1.000000
I20260812 06:20:39.176805 22582 maintenance_manager.cc:643] P 1fe6a521c1804962aa6db14ed3e0eb34: FlushMRSOp(e146f4cac25e43e8aaf1749f1bd43ae5) complete. Timing: real 0.056s	user 0.023s	sys 0.009s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":217,"dirs.run_cpu_time_us":249,"dirs.run_wall_time_us":1627,"drs_written":1,"lbm_read_time_us":62,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2136,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32,"spinlock_wait_cycles":768}
I20260812 06:20:39.177627 22652 maintenance_manager.cc:419] P 1fe6a521c1804962aa6db14ed3e0eb34: Scheduling LogGCOp(e146f4cac25e43e8aaf1749f1bd43ae5): free 124710570 bytes of WAL
I20260812 06:20:39.177937 22582 log_reader.cc:385] T e146f4cac25e43e8aaf1749f1bd43ae5: removed 12 log segments from log reader
I20260812 06:20:39.178012 22582 log.cc:1079] T e146f4cac25e43e8aaf1749f1bd43ae5 P 1fe6a521c1804962aa6db14ed3e0eb34: Deleting log segment in path: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515627637820-22236-0/minicluster-data/ts-0-root/wals/e146f4cac25e43e8aaf1749f1bd43ae5/wal-000000028 (ops 137-141)
I20260812 06:20:39.178071 22582 log.cc:1079] T e146f4cac25e43e8aaf1749f1bd43ae5 P 1fe6a521c1804962aa6db14ed3e0eb34: Deleting log segment in path: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515627637820-22236-0/minicluster-data/ts-0-root/wals/e146f4cac25e43e8aaf1749f1bd43ae5/wal-000000029 (ops 142-146)
I20260812 06:20:39.178130 22582 log.cc:1079] T e146f4cac25e43e8aaf1749f1bd43ae5 P 1fe6a521c1804962aa6db14ed3e0eb34: Deleting log segment in path: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515627637820-22236-0/minicluster-data/ts-0-root/wals/e146f4cac25e43e8aaf1749f1bd43ae5/wal-000000030 (ops 147-151)
I20260812 06:20:39.178174 22582 log.cc:1079] T e146f4cac25e43e8aaf1749f1bd43ae5 P 1fe6a521c1804962aa6db14ed3e0eb34: Deleting log segment in path: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515627637820-22236-0/minicluster-data/ts-0-root/wals/e146f4cac25e43e8aaf1749f1bd43ae5/wal-000000031 (ops 152-156)
I20260812 06:20:39.178210 22582 log.cc:1079] T e146f4cac25e43e8aaf1749f1bd43ae5 P 1fe6a521c1804962aa6db14ed3e0eb34: Deleting log segment in path: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515627637820-22236-0/minicluster-data/ts-0-root/wals/e146f4cac25e43e8aaf1749f1bd43ae5/wal-000000032 (ops 157-161)
I20260812 06:20:39.178251 22582 log.cc:1079] T e146f4cac25e43e8aaf1749f1bd43ae5 P 1fe6a521c1804962aa6db14ed3e0eb34: Deleting log segment in path: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515627637820-22236-0/minicluster-data/ts-0-root/wals/e146f4cac25e43e8aaf1749f1bd43ae5/wal-000000033 (ops 162-166)
I20260812 06:20:39.178287 22582 log.cc:1079] T e146f4cac25e43e8aaf1749f1bd43ae5 P 1fe6a521c1804962aa6db14ed3e0eb34: Deleting log segment in path: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515627637820-22236-0/minicluster-data/ts-0-root/wals/e146f4cac25e43e8aaf1749f1bd43ae5/wal-000000034 (ops 167-171)
I20260812 06:20:39.178328 22582 log.cc:1079] T e146f4cac25e43e8aaf1749f1bd43ae5 P 1fe6a521c1804962aa6db14ed3e0eb34: Deleting log segment in path: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515627637820-22236-0/minicluster-data/ts-0-root/wals/e146f4cac25e43e8aaf1749f1bd43ae5/wal-000000035 (ops 172-176)
I20260812 06:20:39.178373 22582 log.cc:1079] T e146f4cac25e43e8aaf1749f1bd43ae5 P 1fe6a521c1804962aa6db14ed3e0eb34: Deleting log segment in path: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515627637820-22236-0/minicluster-data/ts-0-root/wals/e146f4cac25e43e8aaf1749f1bd43ae5/wal-000000036 (ops 177-181)
I20260812 06:20:39.178413 22582 log.cc:1079] T e146f4cac25e43e8aaf1749f1bd43ae5 P 1fe6a521c1804962aa6db14ed3e0eb34: Deleting log segment in path: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515627637820-22236-0/minicluster-data/ts-0-root/wals/e146f4cac25e43e8aaf1749f1bd43ae5/wal-000000037 (ops 182-186)
I20260812 06:20:39.178452 22582 log.cc:1079] T e146f4cac25e43e8aaf1749f1bd43ae5 P 1fe6a521c1804962aa6db14ed3e0eb34: Deleting log segment in path: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515627637820-22236-0/minicluster-data/ts-0-root/wals/e146f4cac25e43e8aaf1749f1bd43ae5/wal-000000038 (ops 187-191)
I20260812 06:20:39.178493 22582 log.cc:1079] T e146f4cac25e43e8aaf1749f1bd43ae5 P 1fe6a521c1804962aa6db14ed3e0eb34: Deleting log segment in path: /tmp/dist-test-taskTNEayM/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515627637820-22236-0/minicluster-data/ts-0-root/wals/e146f4cac25e43e8aaf1749f1bd43ae5/wal-000000039 (ops 192-196)
I20260812 06:20:39.205186 22582 maintenance_manager.cc:643] P 1fe6a521c1804962aa6db14ed3e0eb34: LogGCOp(e146f4cac25e43e8aaf1749f1bd43ae5) complete. Timing: real 0.027s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:20:39.205729 22652 maintenance_manager.cc:419] P 1fe6a521c1804962aa6db14ed3e0eb34: Scheduling FlushDeltaMemStoresOp(e146f4cac25e43e8aaf1749f1bd43ae5): perf score=6.157687
I20260812 06:20:39.225449 22236 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.213s	user 1.979s	sys 0.162s
I20260812 06:20:39.228642 22582 maintenance_manager.cc:643] P 1fe6a521c1804962aa6db14ed3e0eb34: FlushDeltaMemStoresOp(e146f4cac25e43e8aaf1749f1bd43ae5) complete. Timing: real 0.023s	user 0.016s	sys 0.004s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":9354,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:20:39.229204 22652 maintenance_manager.cc:419] P 1fe6a521c1804962aa6db14ed3e0eb34: Scheduling FlushDeltaMemStoresOp(e146f4cac25e43e8aaf1749f1bd43ae5): perf score=2.188937
I20260812 06:20:39.240374 22582 maintenance_manager.cc:643] P 1fe6a521c1804962aa6db14ed3e0eb34: FlushDeltaMemStoresOp(e146f4cac25e43e8aaf1749f1bd43ae5) complete. Timing: real 0.011s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4673,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:39.240830 22652 maintenance_manager.cc:419] P 1fe6a521c1804962aa6db14ed3e0eb34: Scheduling MajorDeltaCompactionOp(e146f4cac25e43e8aaf1749f1bd43ae5): perf score=1.000000
I20260812 06:20:39.315608 22236 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.090s	user 0.002s	sys 0.000s
I20260812 06:20:39.316326 22236 tablet_server.cc:179] TabletServer@127.21.183.1:0 shutting down...
I20260812 06:20:39.442915 22582 maintenance_manager.cc:643] P 1fe6a521c1804962aa6db14ed3e0eb34: MajorDeltaCompactionOp(e146f4cac25e43e8aaf1749f1bd43ae5) complete. Timing: real 0.202s	user 0.143s	sys 0.058s Metrics: {"cfile_cache_hit":287,"cfile_cache_hit_bytes":11656663,"cfile_cache_miss":547,"cfile_cache_miss_bytes":25425497,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":578,"lbm_read_time_us":11277,"lbm_reads_lt_1ms":579,"lbm_write_time_us":40861,"lbm_writes_lt_1ms":843,"mutex_wait_us":31,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":63232,"thread_start_us":92,"threads_started":1,"update_count":4000}
I20260812 06:20:39.444347 22236 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:39.444761 22236 tablet_replica.cc:333] T e146f4cac25e43e8aaf1749f1bd43ae5 P 1fe6a521c1804962aa6db14ed3e0eb34: stopping tablet replica
I20260812 06:20:39.444943 22236 raft_consensus.cc:2243] T e146f4cac25e43e8aaf1749f1bd43ae5 P 1fe6a521c1804962aa6db14ed3e0eb34 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:39.445169 22236 raft_consensus.cc:2272] T e146f4cac25e43e8aaf1749f1bd43ae5 P 1fe6a521c1804962aa6db14ed3e0eb34 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:39.449213 22236 tablet_server.cc:196] TabletServer@127.21.183.1:0 shutdown complete.
I20260812 06:20:39.516764 22236 master.cc:562] Master@127.21.183.62:44431 shutting down...
I20260812 06:20:39.521117 22236 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 518a5727d2bc45b998559e5e3916911a [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:39.521333 22236 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 518a5727d2bc45b998559e5e3916911a [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:39.521395 22236 tablet_replica.cc:333] T 00000000000000000000000000000000 P 518a5727d2bc45b998559e5e3916911a: stopping tablet replica
I20260812 06:20:39.534503 22236 master.cc:584] Master@127.21.183.62:44431 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5886 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11973 ms total)

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