[==========] 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:17:48.440488 11384 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.11.30.62:35531
I20260812 06:17:48.441504 11384 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:17:48.442127 11384 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:48.449393 11392 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:48.449546 11395 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:48.449699 11384 server_base.cc:1061] running on GCE node
W20260812 06:17:48.449756 11393 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:48.450263 11384 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:48.450380 11384 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:48.450409 11384 hybrid_clock.cc:648] HybridClock initialized: now 1786515468450407 us; error 0 us; skew 500 ppm
I20260812 06:17:48.452209 11384 webserver.cc:533] Webserver started at http://127.11.30.62:43413/ using document root <none> and password file <none>
I20260812 06:17:48.452762 11384 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:48.452821 11384 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:48.453049 11384 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:48.454722 11384 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515468429503-11384-0/minicluster-data/master-0-root/instance:
uuid: "efbc8f8e91fd4552a76758aba858118e"
format_stamp: "Formatted at 2026-08-12 06:17:48 on dist-test-slave-7lbf"
I20260812 06:17:48.458073 11384 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:17:48.459946 11403 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:48.460857 11384 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:48.460958 11384 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515468429503-11384-0/minicluster-data/master-0-root
uuid: "efbc8f8e91fd4552a76758aba858118e"
format_stamp: "Formatted at 2026-08-12 06:17:48 on dist-test-slave-7lbf"
I20260812 06:17:48.461045 11384 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515468429503-11384-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515468429503-11384-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515468429503-11384-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:48.503021 11384 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:48.503708 11384 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:17:48.503886 11384 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:48.511296 11384 rpc_server.cc:307] RPC server started. Bound to: 127.11.30.62:35531
I20260812 06:17:48.511317 11492 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.11.30.62:35531 every 8 connection(s)
I20260812 06:17:48.513715 11493 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:48.519318 11493 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P efbc8f8e91fd4552a76758aba858118e: Bootstrap starting.
I20260812 06:17:48.521780 11493 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P efbc8f8e91fd4552a76758aba858118e: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:48.522714 11493 log.cc:826] T 00000000000000000000000000000000 P efbc8f8e91fd4552a76758aba858118e: Log is configured to *not* fsync() on all Append() calls
I20260812 06:17:48.524457 11493 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P efbc8f8e91fd4552a76758aba858118e: No bootstrap required, opened a new log
I20260812 06:17:48.527297 11493 raft_consensus.cc:359] T 00000000000000000000000000000000 P efbc8f8e91fd4552a76758aba858118e [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "efbc8f8e91fd4552a76758aba858118e" member_type: VOTER }
I20260812 06:17:48.527463 11493 raft_consensus.cc:385] T 00000000000000000000000000000000 P efbc8f8e91fd4552a76758aba858118e [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:48.527523 11493 raft_consensus.cc:740] T 00000000000000000000000000000000 P efbc8f8e91fd4552a76758aba858118e [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: efbc8f8e91fd4552a76758aba858118e, State: Initialized, Role: FOLLOWER
I20260812 06:17:48.528100 11493 consensus_queue.cc:260] T 00000000000000000000000000000000 P efbc8f8e91fd4552a76758aba858118e [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: "efbc8f8e91fd4552a76758aba858118e" member_type: VOTER }
I20260812 06:17:48.528259 11493 raft_consensus.cc:399] T 00000000000000000000000000000000 P efbc8f8e91fd4552a76758aba858118e [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:48.528335 11493 raft_consensus.cc:493] T 00000000000000000000000000000000 P efbc8f8e91fd4552a76758aba858118e [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:48.528455 11493 raft_consensus.cc:3060] T 00000000000000000000000000000000 P efbc8f8e91fd4552a76758aba858118e [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:48.529194 11493 raft_consensus.cc:515] T 00000000000000000000000000000000 P efbc8f8e91fd4552a76758aba858118e [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "efbc8f8e91fd4552a76758aba858118e" member_type: VOTER }
I20260812 06:17:48.529661 11493 leader_election.cc:304] T 00000000000000000000000000000000 P efbc8f8e91fd4552a76758aba858118e [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: efbc8f8e91fd4552a76758aba858118e; no voters: 
I20260812 06:17:48.529978 11493 leader_election.cc:290] T 00000000000000000000000000000000 P efbc8f8e91fd4552a76758aba858118e [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:48.530092 11501 raft_consensus.cc:2804] T 00000000000000000000000000000000 P efbc8f8e91fd4552a76758aba858118e [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:48.530299 11501 raft_consensus.cc:697] T 00000000000000000000000000000000 P efbc8f8e91fd4552a76758aba858118e [term 1 LEADER]: Becoming Leader. State: Replica: efbc8f8e91fd4552a76758aba858118e, State: Running, Role: LEADER
I20260812 06:17:48.530946 11493 sys_catalog.cc:565] T 00000000000000000000000000000000 P efbc8f8e91fd4552a76758aba858118e [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:48.530906 11501 consensus_queue.cc:237] T 00000000000000000000000000000000 P efbc8f8e91fd4552a76758aba858118e [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: "efbc8f8e91fd4552a76758aba858118e" member_type: VOTER }
I20260812 06:17:48.532837 11504 sys_catalog.cc:455] T 00000000000000000000000000000000 P efbc8f8e91fd4552a76758aba858118e [sys.catalog]: SysCatalogTable state changed. Reason: New leader efbc8f8e91fd4552a76758aba858118e. Latest consensus state: current_term: 1 leader_uuid: "efbc8f8e91fd4552a76758aba858118e" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "efbc8f8e91fd4552a76758aba858118e" member_type: VOTER } }
I20260812 06:17:48.532953 11504 sys_catalog.cc:458] T 00000000000000000000000000000000 P efbc8f8e91fd4552a76758aba858118e [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:48.533177 11384 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:48.533231 11502 sys_catalog.cc:455] T 00000000000000000000000000000000 P efbc8f8e91fd4552a76758aba858118e [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "efbc8f8e91fd4552a76758aba858118e" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "efbc8f8e91fd4552a76758aba858118e" member_type: VOTER } }
I20260812 06:17:48.533296 11502 sys_catalog.cc:458] T 00000000000000000000000000000000 P efbc8f8e91fd4552a76758aba858118e [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:48.533347 11528 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:48.535701 11528 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:48.540139 11528 catalog_manager.cc:1383] Generated new cluster ID: b98c2f381a8b4529bc69a049b875ca79
I20260812 06:17:48.540200 11528 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:48.553262 11528 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:48.554096 11528 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:48.561285 11528 catalog_manager.cc:6092] T 00000000000000000000000000000000 P efbc8f8e91fd4552a76758aba858118e: Generated new TSK 0
I20260812 06:17:48.561901 11528 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:48.565783 11384 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:48.568568 11538 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:48.568650 11541 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:48.568702 11539 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:48.568851 11384 server_base.cc:1061] running on GCE node
I20260812 06:17:48.569097 11384 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:48.569154 11384 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:48.569175 11384 hybrid_clock.cc:648] HybridClock initialized: now 1786515468569174 us; error 0 us; skew 500 ppm
I20260812 06:17:48.570066 11384 webserver.cc:533] Webserver started at http://127.11.30.1:32933/ using document root <none> and password file <none>
I20260812 06:17:48.570226 11384 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:48.570282 11384 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:48.570353 11384 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:48.570785 11384 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515468429503-11384-0/minicluster-data/ts-0-root/instance:
uuid: "fe8fb96149534a8cb790a299863bb828"
format_stamp: "Formatted at 2026-08-12 06:17:48 on dist-test-slave-7lbf"
I20260812 06:17:48.572530 11384 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:48.573679 11557 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:48.573940 11384 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:48.574004 11384 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515468429503-11384-0/minicluster-data/ts-0-root
uuid: "fe8fb96149534a8cb790a299863bb828"
format_stamp: "Formatted at 2026-08-12 06:17:48 on dist-test-slave-7lbf"
I20260812 06:17:48.574081 11384 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515468429503-11384-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515468429503-11384-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515468429503-11384-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:48.582747 11384 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:48.583141 11384 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:48.583585 11384 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:48.584448 11384 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:48.584547 11384 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:48.584621 11384 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:48.584652 11384 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:48.591009 11384 rpc_server.cc:307] RPC server started. Bound to: 127.11.30.1:45213
I20260812 06:17:48.591065 11666 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.11.30.1:45213 every 8 connection(s)
I20260812 06:17:48.600158 11668 heartbeater.cc:344] Connected to a master server at 127.11.30.62:35531
I20260812 06:17:48.600374 11668 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:48.600819 11668 heartbeater.cc:507] Master 127.11.30.62:35531 requested a full tablet report, sending...
I20260812 06:17:48.602348 11429 ts_manager.cc:194] Registered new tserver with Master: fe8fb96149534a8cb790a299863bb828 (127.11.30.1:45213)
I20260812 06:17:48.602751 11384 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.011159273s
I20260812 06:17:48.603789 11429 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:51920
I20260812 06:17:48.613009 11429 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:51926:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:17:48.627490 11605 tablet_service.cc:1511] Processing CreateTablet for tablet 1bda84d5612240758cbca4bcb531ac15 (DEFAULT_TABLE table=heavy-update-compaction-test [id=97f5b94b6e414394a4b6d265dfcd0300]), partition=
I20260812 06:17:48.627911 11605 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 1bda84d5612240758cbca4bcb531ac15. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:48.630064 11695 tablet_bootstrap.cc:492] T 1bda84d5612240758cbca4bcb531ac15 P fe8fb96149534a8cb790a299863bb828: Bootstrap starting.
I20260812 06:17:48.631107 11695 tablet_bootstrap.cc:654] T 1bda84d5612240758cbca4bcb531ac15 P fe8fb96149534a8cb790a299863bb828: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:48.632146 11695 tablet_bootstrap.cc:492] T 1bda84d5612240758cbca4bcb531ac15 P fe8fb96149534a8cb790a299863bb828: No bootstrap required, opened a new log
I20260812 06:17:48.632236 11695 ts_tablet_manager.cc:1403] T 1bda84d5612240758cbca4bcb531ac15 P fe8fb96149534a8cb790a299863bb828: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:48.632628 11695 raft_consensus.cc:359] T 1bda84d5612240758cbca4bcb531ac15 P fe8fb96149534a8cb790a299863bb828 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "fe8fb96149534a8cb790a299863bb828" member_type: VOTER last_known_addr { host: "127.11.30.1" port: 45213 } }
I20260812 06:17:48.632725 11695 raft_consensus.cc:385] T 1bda84d5612240758cbca4bcb531ac15 P fe8fb96149534a8cb790a299863bb828 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:48.632756 11695 raft_consensus.cc:740] T 1bda84d5612240758cbca4bcb531ac15 P fe8fb96149534a8cb790a299863bb828 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: fe8fb96149534a8cb790a299863bb828, State: Initialized, Role: FOLLOWER
I20260812 06:17:48.632882 11695 consensus_queue.cc:260] T 1bda84d5612240758cbca4bcb531ac15 P fe8fb96149534a8cb790a299863bb828 [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: "fe8fb96149534a8cb790a299863bb828" member_type: VOTER last_known_addr { host: "127.11.30.1" port: 45213 } }
I20260812 06:17:48.632983 11695 raft_consensus.cc:399] T 1bda84d5612240758cbca4bcb531ac15 P fe8fb96149534a8cb790a299863bb828 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:48.633059 11695 raft_consensus.cc:493] T 1bda84d5612240758cbca4bcb531ac15 P fe8fb96149534a8cb790a299863bb828 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:48.633111 11695 raft_consensus.cc:3060] T 1bda84d5612240758cbca4bcb531ac15 P fe8fb96149534a8cb790a299863bb828 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:48.633862 11695 raft_consensus.cc:515] T 1bda84d5612240758cbca4bcb531ac15 P fe8fb96149534a8cb790a299863bb828 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "fe8fb96149534a8cb790a299863bb828" member_type: VOTER last_known_addr { host: "127.11.30.1" port: 45213 } }
I20260812 06:17:48.634009 11695 leader_election.cc:304] T 1bda84d5612240758cbca4bcb531ac15 P fe8fb96149534a8cb790a299863bb828 [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: fe8fb96149534a8cb790a299863bb828; no voters: 
I20260812 06:17:48.634208 11695 leader_election.cc:290] T 1bda84d5612240758cbca4bcb531ac15 P fe8fb96149534a8cb790a299863bb828 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:48.634311 11697 raft_consensus.cc:2804] T 1bda84d5612240758cbca4bcb531ac15 P fe8fb96149534a8cb790a299863bb828 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:48.634639 11695 ts_tablet_manager.cc:1434] T 1bda84d5612240758cbca4bcb531ac15 P fe8fb96149534a8cb790a299863bb828: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:17:48.634651 11697 raft_consensus.cc:697] T 1bda84d5612240758cbca4bcb531ac15 P fe8fb96149534a8cb790a299863bb828 [term 1 LEADER]: Becoming Leader. State: Replica: fe8fb96149534a8cb790a299863bb828, State: Running, Role: LEADER
I20260812 06:17:48.634940 11668 heartbeater.cc:499] Master 127.11.30.62:35531 was elected leader, sending a full tablet report...
I20260812 06:17:48.634881 11697 consensus_queue.cc:237] T 1bda84d5612240758cbca4bcb531ac15 P fe8fb96149534a8cb790a299863bb828 [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: "fe8fb96149534a8cb790a299863bb828" member_type: VOTER last_known_addr { host: "127.11.30.1" port: 45213 } }
I20260812 06:17:48.637614 11429 catalog_manager.cc:5719] T 1bda84d5612240758cbca4bcb531ac15 P fe8fb96149534a8cb790a299863bb828 reported cstate change: term changed from 0 to 1, leader changed from <none> to fe8fb96149534a8cb790a299863bb828 (127.11.30.1). New cstate: current_term: 1 leader_uuid: "fe8fb96149534a8cb790a299863bb828" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "fe8fb96149534a8cb790a299863bb828" member_type: VOTER last_known_addr { host: "127.11.30.1" port: 45213 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:48.708329 11384 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.061s	user 0.019s	sys 0.013s
I20260812 06:17:48.841998 11671 maintenance_manager.cc:419] P fe8fb96149534a8cb790a299863bb828: Scheduling FlushMRSOp(1bda84d5612240758cbca4bcb531ac15): perf score=19.054940
I20260812 06:17:48.986480 11565 maintenance_manager.cc:643] P fe8fb96149534a8cb790a299863bb828: FlushMRSOp(1bda84d5612240758cbca4bcb531ac15) complete. Timing: real 0.144s	user 0.110s	sys 0.032s Metrics: {"bytes_written":8615323,"cfile_init":1,"compiler_manager_pool.queue_time_us":208,"delete_count":0,"dirs.queue_time_us":55,"dirs.run_cpu_time_us":200,"dirs.run_wall_time_us":813,"drs_written":1,"lbm_read_time_us":73,"lbm_reads_lt_1ms":4,"lbm_write_time_us":35680,"lbm_writes_lt_1ms":667,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"thread_start_us":119,"threads_started":1,"update_count":1050}
I20260812 06:17:48.987469 11671 maintenance_manager.cc:419] P fe8fb96149534a8cb790a299863bb828: Scheduling LogGCOp(1bda84d5612240758cbca4bcb531ac15): free 20743880 bytes of WAL
I20260812 06:17:48.987746 11565 log_reader.cc:385] T 1bda84d5612240758cbca4bcb531ac15: removed 2 log segments from log reader
I20260812 06:17:48.987800 11565 log.cc:1079] T 1bda84d5612240758cbca4bcb531ac15 P fe8fb96149534a8cb790a299863bb828: Deleting log segment in path: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515468429503-11384-0/minicluster-data/ts-0-root/wals/1bda84d5612240758cbca4bcb531ac15/wal-000000001 (ops 1-6)
I20260812 06:17:48.987900 11565 log.cc:1079] T 1bda84d5612240758cbca4bcb531ac15 P fe8fb96149534a8cb790a299863bb828: Deleting log segment in path: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515468429503-11384-0/minicluster-data/ts-0-root/wals/1bda84d5612240758cbca4bcb531ac15/wal-000000002 (ops 7-11)
I20260812 06:17:48.992101 11565 maintenance_manager.cc:643] P fe8fb96149534a8cb790a299863bb828: LogGCOp(1bda84d5612240758cbca4bcb531ac15) complete. Timing: real 0.004s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:17:48.992506 11671 maintenance_manager.cc:419] P fe8fb96149534a8cb790a299863bb828: Scheduling UndoDeltaBlockGCOp(1bda84d5612240758cbca4bcb531ac15): 16411391 bytes on disk
I20260812 06:17:48.993337 11565 maintenance_manager.cc:643] P fe8fb96149534a8cb790a299863bb828: UndoDeltaBlockGCOp(1bda84d5612240758cbca4bcb531ac15) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":103,"lbm_reads_lt_1ms":4}
I20260812 06:17:48.993855 11671 maintenance_manager.cc:419] P fe8fb96149534a8cb790a299863bb828: Scheduling FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15): perf score=2.188937
I20260812 06:17:49.008684 11565 maintenance_manager.cc:643] P fe8fb96149534a8cb790a299863bb828: FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5166,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:49.009357 11671 maintenance_manager.cc:419] P fe8fb96149534a8cb790a299863bb828: Scheduling MajorDeltaCompactionOp(1bda84d5612240758cbca4bcb531ac15): perf score=1.000000
I20260812 06:17:49.124799 11565 maintenance_manager.cc:643] P fe8fb96149534a8cb790a299863bb828: MajorDeltaCompactionOp(1bda84d5612240758cbca4bcb531ac15) complete. Timing: real 0.115s	user 0.097s	sys 0.013s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16569856,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":641,"lbm_read_time_us":7527,"lbm_reads_lt_1ms":360,"lbm_write_time_us":18699,"lbm_writes_lt_1ms":343,"peak_mem_usage":38262756,"reinsert_count":0,"thread_start_us":271,"threads_started":5,"update_count":1500}
I20260812 06:17:49.125275 11671 maintenance_manager.cc:419] P fe8fb96149534a8cb790a299863bb828: Scheduling FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15): perf score=10.126437
I20260812 06:17:49.157610 11565 maintenance_manager.cc:643] P fe8fb96149534a8cb790a299863bb828: FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15) complete. Timing: real 0.032s	user 0.017s	sys 0.012s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":12525,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:49.158094 11671 maintenance_manager.cc:419] P fe8fb96149534a8cb790a299863bb828: Scheduling MajorDeltaCompactionOp(1bda84d5612240758cbca4bcb531ac15): perf score=1.000000
I20260812 06:17:49.258175 11565 maintenance_manager.cc:643] P fe8fb96149534a8cb790a299863bb828: MajorDeltaCompactionOp(1bda84d5612240758cbca4bcb531ac15) complete. Timing: real 0.100s	user 0.084s	sys 0.016s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16569747,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":237,"lbm_read_time_us":7528,"lbm_reads_lt_1ms":363,"lbm_write_time_us":17686,"lbm_writes_lt_1ms":343,"mutex_wait_us":42,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":38400,"update_count":1500}
I20260812 06:17:49.258617 11671 maintenance_manager.cc:419] P fe8fb96149534a8cb790a299863bb828: Scheduling FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15): perf score=10.126437
I20260812 06:17:49.297411 11565 maintenance_manager.cc:643] P fe8fb96149534a8cb790a299863bb828: FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15) complete. Timing: real 0.039s	user 0.020s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14562,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:49.297986 11671 maintenance_manager.cc:419] P fe8fb96149534a8cb790a299863bb828: Scheduling FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15): perf score=2.188937
I20260812 06:17:49.308537 11565 maintenance_manager.cc:643] P fe8fb96149534a8cb790a299863bb828: FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15) complete. Timing: real 0.010s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3819,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:49.309062 11671 maintenance_manager.cc:419] P fe8fb96149534a8cb790a299863bb828: Scheduling MajorDeltaCompactionOp(1bda84d5612240758cbca4bcb531ac15): perf score=1.000000
I20260812 06:17:49.437338 11565 maintenance_manager.cc:643] P fe8fb96149534a8cb790a299863bb828: MajorDeltaCompactionOp(1bda84d5612240758cbca4bcb531ac15) complete. Timing: real 0.128s	user 0.108s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":211,"lbm_read_time_us":9653,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23973,"lbm_writes_lt_1ms":443,"mutex_wait_us":26,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11008,"update_count":2000}
I20260812 06:17:49.437892 11671 maintenance_manager.cc:419] P fe8fb96149534a8cb790a299863bb828: Scheduling FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15): perf score=10.126437
I20260812 06:17:49.479945 11565 maintenance_manager.cc:643] P fe8fb96149534a8cb790a299863bb828: FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15) complete. Timing: real 0.042s	user 0.023s	sys 0.004s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":12406,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:49.480412 11671 maintenance_manager.cc:419] P fe8fb96149534a8cb790a299863bb828: Scheduling FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15): perf score=2.188937
I20260812 06:17:49.495499 11565 maintenance_manager.cc:643] P fe8fb96149534a8cb790a299863bb828: FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15) complete. Timing: real 0.015s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5582,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:49.495978 11671 maintenance_manager.cc:419] P fe8fb96149534a8cb790a299863bb828: Scheduling MajorDeltaCompactionOp(1bda84d5612240758cbca4bcb531ac15): perf score=1.000000
I20260812 06:17:49.612334 11565 maintenance_manager.cc:643] P fe8fb96149534a8cb790a299863bb828: MajorDeltaCompactionOp(1bda84d5612240758cbca4bcb531ac15) complete. Timing: real 0.116s	user 0.093s	sys 0.023s 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":1083,"lbm_read_time_us":8122,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21853,"lbm_writes_lt_1ms":443,"mutex_wait_us":316,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":15744,"update_count":2000}
I20260812 06:17:49.612917 11671 maintenance_manager.cc:419] P fe8fb96149534a8cb790a299863bb828: Scheduling FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15): perf score=10.126437
I20260812 06:17:49.659478 11565 maintenance_manager.cc:643] P fe8fb96149534a8cb790a299863bb828: FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15) complete. Timing: real 0.046s	user 0.027s	sys 0.017s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":23145,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":300,"reinsert_count":0,"update_count":1500}
I20260812 06:17:49.659912 11671 maintenance_manager.cc:419] P fe8fb96149534a8cb790a299863bb828: Scheduling FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15): perf score=2.188937
I20260812 06:17:49.670404 11565 maintenance_manager.cc:643] P fe8fb96149534a8cb790a299863bb828: FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15) complete. Timing: real 0.010s	user 0.008s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3643,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:49.670951 11671 maintenance_manager.cc:419] P fe8fb96149534a8cb790a299863bb828: Scheduling MajorDeltaCompactionOp(1bda84d5612240758cbca4bcb531ac15): perf score=1.000000
I20260812 06:17:49.786711 11565 maintenance_manager.cc:643] P fe8fb96149534a8cb790a299863bb828: MajorDeltaCompactionOp(1bda84d5612240758cbca4bcb531ac15) complete. Timing: real 0.116s	user 0.092s	sys 0.021s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":643,"lbm_read_time_us":9082,"lbm_reads_lt_1ms":472,"lbm_write_time_us":20107,"lbm_writes_lt_1ms":443,"mutex_wait_us":27,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7552,"update_count":2000}
I20260812 06:17:49.787324 11671 maintenance_manager.cc:419] P fe8fb96149534a8cb790a299863bb828: Scheduling FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15): perf score=10.126437
I20260812 06:17:49.842286 11565 maintenance_manager.cc:643] P fe8fb96149534a8cb790a299863bb828: FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15) complete. Timing: real 0.055s	user 0.036s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15937,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:49.842852 11671 maintenance_manager.cc:419] P fe8fb96149534a8cb790a299863bb828: Scheduling FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15): perf score=2.188937
I20260812 06:17:49.858443 11565 maintenance_manager.cc:643] P fe8fb96149534a8cb790a299863bb828: FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15) complete. Timing: real 0.015s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5912,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:49.858946 11671 maintenance_manager.cc:419] P fe8fb96149534a8cb790a299863bb828: Scheduling MajorDeltaCompactionOp(1bda84d5612240758cbca4bcb531ac15): perf score=1.000000
I20260812 06:17:50.005288 11565 maintenance_manager.cc:643] P fe8fb96149534a8cb790a299863bb828: MajorDeltaCompactionOp(1bda84d5612240758cbca4bcb531ac15) complete. Timing: real 0.146s	user 0.094s	sys 0.052s 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":429,"lbm_read_time_us":10340,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24350,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4224,"update_count":2000}
I20260812 06:17:50.005941 11671 maintenance_manager.cc:419] P fe8fb96149534a8cb790a299863bb828: Scheduling FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15): perf score=10.126437
I20260812 06:17:50.047277 11565 maintenance_manager.cc:643] P fe8fb96149534a8cb790a299863bb828: FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15) complete. Timing: real 0.041s	user 0.001s	sys 0.038s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17924,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:50.047788 11671 maintenance_manager.cc:419] P fe8fb96149534a8cb790a299863bb828: Scheduling FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15): perf score=2.188937
I20260812 06:17:50.061326 11565 maintenance_manager.cc:643] P fe8fb96149534a8cb790a299863bb828: FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15) complete. Timing: real 0.013s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4732,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:50.062039 11671 maintenance_manager.cc:419] P fe8fb96149534a8cb790a299863bb828: Scheduling MajorDeltaCompactionOp(1bda84d5612240758cbca4bcb531ac15): perf score=1.000000
I20260812 06:17:50.179901 11565 maintenance_manager.cc:643] P fe8fb96149534a8cb790a299863bb828: MajorDeltaCompactionOp(1bda84d5612240758cbca4bcb531ac15) complete. Timing: real 0.118s	user 0.093s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":351,"lbm_read_time_us":9330,"lbm_reads_lt_1ms":464,"lbm_write_time_us":20970,"lbm_writes_lt_1ms":443,"mutex_wait_us":85,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:17:50.180485 11671 maintenance_manager.cc:419] P fe8fb96149534a8cb790a299863bb828: Scheduling FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15): perf score=10.126437
I20260812 06:17:50.216547 11565 maintenance_manager.cc:643] P fe8fb96149534a8cb790a299863bb828: FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15) complete. Timing: real 0.036s	user 0.029s	sys 0.004s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13326,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:50.217067 11671 maintenance_manager.cc:419] P fe8fb96149534a8cb790a299863bb828: Scheduling FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15): perf score=2.188937
I20260812 06:17:50.232404 11565 maintenance_manager.cc:643] P fe8fb96149534a8cb790a299863bb828: FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15) complete. Timing: real 0.015s	user 0.006s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5788,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:50.232901 11671 maintenance_manager.cc:419] P fe8fb96149534a8cb790a299863bb828: Scheduling FlushMRSOp(1bda84d5612240758cbca4bcb531ac15): perf score=1.000000
I20260812 06:17:50.264649 11565 maintenance_manager.cc:643] P fe8fb96149534a8cb790a299863bb828: FlushMRSOp(1bda84d5612240758cbca4bcb531ac15) complete. Timing: real 0.032s	user 0.030s	sys 0.000s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":41,"dirs.run_cpu_time_us":250,"dirs.run_wall_time_us":1462,"drs_written":1,"lbm_read_time_us":40,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1466,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:17:50.265592 11671 maintenance_manager.cc:419] P fe8fb96149534a8cb790a299863bb828: Scheduling LogGCOp(1bda84d5612240758cbca4bcb531ac15): free 124710288 bytes of WAL
I20260812 06:17:50.265828 11565 log_reader.cc:385] T 1bda84d5612240758cbca4bcb531ac15: removed 12 log segments from log reader
I20260812 06:17:50.265878 11565 log.cc:1079] T 1bda84d5612240758cbca4bcb531ac15 P fe8fb96149534a8cb790a299863bb828: Deleting log segment in path: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515468429503-11384-0/minicluster-data/ts-0-root/wals/1bda84d5612240758cbca4bcb531ac15/wal-000000003 (ops 12-16)
I20260812 06:17:50.265910 11565 log.cc:1079] T 1bda84d5612240758cbca4bcb531ac15 P fe8fb96149534a8cb790a299863bb828: Deleting log segment in path: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515468429503-11384-0/minicluster-data/ts-0-root/wals/1bda84d5612240758cbca4bcb531ac15/wal-000000004 (ops 17-21)
I20260812 06:17:50.265931 11565 log.cc:1079] T 1bda84d5612240758cbca4bcb531ac15 P fe8fb96149534a8cb790a299863bb828: Deleting log segment in path: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515468429503-11384-0/minicluster-data/ts-0-root/wals/1bda84d5612240758cbca4bcb531ac15/wal-000000005 (ops 22-26)
I20260812 06:17:50.265962 11565 log.cc:1079] T 1bda84d5612240758cbca4bcb531ac15 P fe8fb96149534a8cb790a299863bb828: Deleting log segment in path: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515468429503-11384-0/minicluster-data/ts-0-root/wals/1bda84d5612240758cbca4bcb531ac15/wal-000000006 (ops 27-31)
I20260812 06:17:50.265993 11565 log.cc:1079] T 1bda84d5612240758cbca4bcb531ac15 P fe8fb96149534a8cb790a299863bb828: Deleting log segment in path: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515468429503-11384-0/minicluster-data/ts-0-root/wals/1bda84d5612240758cbca4bcb531ac15/wal-000000007 (ops 32-36)
I20260812 06:17:50.266026 11565 log.cc:1079] T 1bda84d5612240758cbca4bcb531ac15 P fe8fb96149534a8cb790a299863bb828: Deleting log segment in path: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515468429503-11384-0/minicluster-data/ts-0-root/wals/1bda84d5612240758cbca4bcb531ac15/wal-000000008 (ops 37-41)
I20260812 06:17:50.266057 11565 log.cc:1079] T 1bda84d5612240758cbca4bcb531ac15 P fe8fb96149534a8cb790a299863bb828: Deleting log segment in path: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515468429503-11384-0/minicluster-data/ts-0-root/wals/1bda84d5612240758cbca4bcb531ac15/wal-000000009 (ops 42-46)
I20260812 06:17:50.266086 11565 log.cc:1079] T 1bda84d5612240758cbca4bcb531ac15 P fe8fb96149534a8cb790a299863bb828: Deleting log segment in path: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515468429503-11384-0/minicluster-data/ts-0-root/wals/1bda84d5612240758cbca4bcb531ac15/wal-000000010 (ops 47-51)
I20260812 06:17:50.266116 11565 log.cc:1079] T 1bda84d5612240758cbca4bcb531ac15 P fe8fb96149534a8cb790a299863bb828: Deleting log segment in path: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515468429503-11384-0/minicluster-data/ts-0-root/wals/1bda84d5612240758cbca4bcb531ac15/wal-000000011 (ops 52-56)
I20260812 06:17:50.266147 11565 log.cc:1079] T 1bda84d5612240758cbca4bcb531ac15 P fe8fb96149534a8cb790a299863bb828: Deleting log segment in path: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515468429503-11384-0/minicluster-data/ts-0-root/wals/1bda84d5612240758cbca4bcb531ac15/wal-000000012 (ops 57-61)
I20260812 06:17:50.266178 11565 log.cc:1079] T 1bda84d5612240758cbca4bcb531ac15 P fe8fb96149534a8cb790a299863bb828: Deleting log segment in path: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515468429503-11384-0/minicluster-data/ts-0-root/wals/1bda84d5612240758cbca4bcb531ac15/wal-000000013 (ops 62-66)
I20260812 06:17:50.266208 11565 log.cc:1079] T 1bda84d5612240758cbca4bcb531ac15 P fe8fb96149534a8cb790a299863bb828: Deleting log segment in path: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515468429503-11384-0/minicluster-data/ts-0-root/wals/1bda84d5612240758cbca4bcb531ac15/wal-000000014 (ops 67-71)
I20260812 06:17:50.290856 11565 maintenance_manager.cc:643] P fe8fb96149534a8cb790a299863bb828: LogGCOp(1bda84d5612240758cbca4bcb531ac15) complete. Timing: real 0.025s	user 0.000s	sys 0.024s Metrics: {}
I20260812 06:17:50.291477 11671 maintenance_manager.cc:419] P fe8fb96149534a8cb790a299863bb828: Scheduling UndoDeltaBlockGCOp(1bda84d5612240758cbca4bcb531ac15): 471 bytes on disk
I20260812 06:17:50.291910 11565 maintenance_manager.cc:643] P fe8fb96149534a8cb790a299863bb828: UndoDeltaBlockGCOp(1bda84d5612240758cbca4bcb531ac15) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4}
I20260812 06:17:50.292534 11671 maintenance_manager.cc:419] P fe8fb96149534a8cb790a299863bb828: Scheduling FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15): perf score=4.173312
I20260812 06:17:50.305830 11565 maintenance_manager.cc:643] P fe8fb96149534a8cb790a299863bb828: FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15) complete. Timing: real 0.013s	user 0.005s	sys 0.008s Metrics: {"bytes_written":5743633,"delete_count":0,"lbm_write_time_us":5185,"lbm_writes_lt_1ms":143,"reinsert_count":0,"update_count":700}
I20260812 06:17:50.306246 11671 maintenance_manager.cc:419] P fe8fb96149534a8cb790a299863bb828: Scheduling FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15): perf score=1.196750
I20260812 06:17:50.313977 11565 maintenance_manager.cc:643] P fe8fb96149534a8cb790a299863bb828: FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15) complete. Timing: real 0.008s	user 0.007s	sys 0.000s Metrics: {"bytes_written":2461654,"delete_count":0,"lbm_write_time_us":2181,"lbm_writes_lt_1ms":63,"reinsert_count":0,"update_count":300}
I20260812 06:17:50.314427 11671 maintenance_manager.cc:419] P fe8fb96149534a8cb790a299863bb828: Scheduling MajorDeltaCompactionOp(1bda84d5612240758cbca4bcb531ac15): perf score=1.000000
I20260812 06:17:50.485814 11565 maintenance_manager.cc:643] P fe8fb96149534a8cb790a299863bb828: MajorDeltaCompactionOp(1bda84d5612240758cbca4bcb531ac15) complete. Timing: real 0.171s	user 0.118s	sys 0.044s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877302,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":970,"lbm_read_time_us":10077,"lbm_reads_lt_1ms":674,"lbm_write_time_us":34410,"lbm_writes_lt_1ms":643,"mutex_wait_us":35,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":4096,"thread_start_us":73,"threads_started":1,"update_count":3000}
I20260812 06:17:50.486614 11671 maintenance_manager.cc:419] P fe8fb96149534a8cb790a299863bb828: Scheduling FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15): perf score=14.095187
I20260812 06:17:50.530970 11565 maintenance_manager.cc:643] P fe8fb96149534a8cb790a299863bb828: FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15) complete. Timing: real 0.044s	user 0.034s	sys 0.008s Metrics: {"bytes_written":16409899,"delete_count":0,"lbm_write_time_us":18880,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:50.531410 11671 maintenance_manager.cc:419] P fe8fb96149534a8cb790a299863bb828: Scheduling FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15): perf score=2.188937
I20260812 06:17:50.543622 11565 maintenance_manager.cc:643] P fe8fb96149534a8cb790a299863bb828: FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4272,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:50.544203 11671 maintenance_manager.cc:419] P fe8fb96149534a8cb790a299863bb828: Scheduling MajorDeltaCompactionOp(1bda84d5612240758cbca4bcb531ac15): perf score=1.000000
I20260812 06:17:50.694752 11565 maintenance_manager.cc:643] P fe8fb96149534a8cb790a299863bb828: MajorDeltaCompactionOp(1bda84d5612240758cbca4bcb531ac15) complete. Timing: real 0.150s	user 0.126s	sys 0.021s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774686,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":187,"lbm_read_time_us":10852,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28198,"lbm_writes_lt_1ms":543,"mutex_wait_us":52,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":20736,"update_count":2500}
I20260812 06:17:50.695576 11671 maintenance_manager.cc:419] P fe8fb96149534a8cb790a299863bb828: Scheduling FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15): perf score=12.110812
I20260812 06:17:50.734434 11565 maintenance_manager.cc:643] P fe8fb96149534a8cb790a299863bb828: FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15) complete. Timing: real 0.039s	user 0.021s	sys 0.013s Metrics: {"bytes_written":13579241,"delete_count":0,"lbm_write_time_us":14903,"lbm_writes_lt_1ms":334,"reinsert_count":0,"update_count":1655}
I20260812 06:17:50.735011 11671 maintenance_manager.cc:419] P fe8fb96149534a8cb790a299863bb828: Scheduling FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15): perf score=2.188937
I20260812 06:17:50.753906 11565 maintenance_manager.cc:643] P fe8fb96149534a8cb790a299863bb828: FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15) complete. Timing: real 0.019s	user 0.004s	sys 0.009s Metrics: {"bytes_written":3241134,"delete_count":0,"lbm_write_time_us":4672,"lbm_writes_lt_1ms":82,"reinsert_count":0,"update_count":395}
I20260812 06:17:50.754348 11671 maintenance_manager.cc:419] P fe8fb96149534a8cb790a299863bb828: Scheduling FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15): perf score=2.188937
I20260812 06:17:50.763216 11565 maintenance_manager.cc:643] P fe8fb96149534a8cb790a299863bb828: FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15) complete. Timing: real 0.009s	user 0.004s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3344,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:50.763590 11671 maintenance_manager.cc:419] P fe8fb96149534a8cb790a299863bb828: Scheduling MajorDeltaCompactionOp(1bda84d5612240758cbca4bcb531ac15): perf score=1.000000
I20260812 06:17:50.937013 11565 maintenance_manager.cc:643] P fe8fb96149534a8cb790a299863bb828: MajorDeltaCompactionOp(1bda84d5612240758cbca4bcb531ac15) complete. Timing: real 0.173s	user 0.133s	sys 0.029s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774780,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":616,"lbm_read_time_us":11096,"lbm_reads_lt_1ms":573,"lbm_write_time_us":27055,"lbm_writes_lt_1ms":543,"mutex_wait_us":279,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11392,"update_count":2500}
I20260812 06:17:50.937551 11671 maintenance_manager.cc:419] P fe8fb96149534a8cb790a299863bb828: Scheduling FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15): perf score=14.095187
I20260812 06:17:50.995932 11565 maintenance_manager.cc:643] P fe8fb96149534a8cb790a299863bb828: FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15) complete. Timing: real 0.058s	user 0.025s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19407,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:50.996479 11671 maintenance_manager.cc:419] P fe8fb96149534a8cb790a299863bb828: Scheduling FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15): perf score=2.188937
I20260812 06:17:51.006824 11565 maintenance_manager.cc:643] P fe8fb96149534a8cb790a299863bb828: FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15) complete. Timing: real 0.010s	user 0.004s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3972,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:51.007426 11671 maintenance_manager.cc:419] P fe8fb96149534a8cb790a299863bb828: Scheduling MajorDeltaCompactionOp(1bda84d5612240758cbca4bcb531ac15): perf score=1.000000
I20260812 06:17:51.170512 11565 maintenance_manager.cc:643] P fe8fb96149534a8cb790a299863bb828: MajorDeltaCompactionOp(1bda84d5612240758cbca4bcb531ac15) complete. Timing: real 0.163s	user 0.108s	sys 0.048s 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":201,"lbm_read_time_us":12012,"lbm_reads_lt_1ms":572,"lbm_write_time_us":24550,"lbm_writes_lt_1ms":543,"mutex_wait_us":35,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9984,"update_count":2500}
I20260812 06:17:51.171191 11671 maintenance_manager.cc:419] P fe8fb96149534a8cb790a299863bb828: Scheduling FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15): perf score=14.095187
I20260812 06:17:51.222705 11565 maintenance_manager.cc:643] P fe8fb96149534a8cb790a299863bb828: FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15) complete. Timing: real 0.051s	user 0.026s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":16894,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:51.223248 11671 maintenance_manager.cc:419] P fe8fb96149534a8cb790a299863bb828: Scheduling FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15): perf score=2.188937
I20260812 06:17:51.233768 11565 maintenance_manager.cc:643] P fe8fb96149534a8cb790a299863bb828: FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3911,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:51.234231 11671 maintenance_manager.cc:419] P fe8fb96149534a8cb790a299863bb828: Scheduling MajorDeltaCompactionOp(1bda84d5612240758cbca4bcb531ac15): perf score=1.000000
I20260812 06:17:51.412027 11565 maintenance_manager.cc:643] P fe8fb96149534a8cb790a299863bb828: MajorDeltaCompactionOp(1bda84d5612240758cbca4bcb531ac15) complete. Timing: real 0.178s	user 0.105s	sys 0.062s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":155,"lbm_read_time_us":13421,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26993,"lbm_writes_lt_1ms":543,"mutex_wait_us":25,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4864,"update_count":2500}
I20260812 06:17:51.412876 11671 maintenance_manager.cc:419] P fe8fb96149534a8cb790a299863bb828: Scheduling FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15): perf score=14.095187
I20260812 06:17:51.471935 11565 maintenance_manager.cc:643] P fe8fb96149534a8cb790a299863bb828: FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15) complete. Timing: real 0.059s	user 0.020s	sys 0.036s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":24408,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:17:51.472553 11671 maintenance_manager.cc:419] P fe8fb96149534a8cb790a299863bb828: Scheduling FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15): perf score=2.188937
I20260812 06:17:51.487884 11565 maintenance_manager.cc:643] P fe8fb96149534a8cb790a299863bb828: FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15) complete. Timing: real 0.015s	user 0.006s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5734,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:51.488422 11671 maintenance_manager.cc:419] P fe8fb96149534a8cb790a299863bb828: Scheduling MajorDeltaCompactionOp(1bda84d5612240758cbca4bcb531ac15): perf score=1.000000
I20260812 06:17:51.646027 11565 maintenance_manager.cc:643] P fe8fb96149534a8cb790a299863bb828: MajorDeltaCompactionOp(1bda84d5612240758cbca4bcb531ac15) complete. Timing: real 0.157s	user 0.090s	sys 0.064s 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":196,"lbm_read_time_us":11734,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25355,"lbm_writes_lt_1ms":543,"mutex_wait_us":27,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:17:51.646621 11671 maintenance_manager.cc:419] P fe8fb96149534a8cb790a299863bb828: Scheduling FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15): perf score=11.118625
I20260812 06:17:51.693076 11565 maintenance_manager.cc:643] P fe8fb96149534a8cb790a299863bb828: FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15) complete. Timing: real 0.046s	user 0.013s	sys 0.028s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":17938,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:51.693580 11671 maintenance_manager.cc:419] P fe8fb96149534a8cb790a299863bb828: Scheduling FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15): perf score=2.188937
I20260812 06:17:51.709507 11565 maintenance_manager.cc:643] P fe8fb96149534a8cb790a299863bb828: FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15) complete. Timing: real 0.016s	user 0.013s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6152,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:51.709956 11671 maintenance_manager.cc:419] P fe8fb96149534a8cb790a299863bb828: Scheduling FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15): perf score=2.188937
I20260812 06:17:51.726267 11565 maintenance_manager.cc:643] P fe8fb96149534a8cb790a299863bb828: FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15) complete. Timing: real 0.016s	user 0.012s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3235,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:51.726796 11671 maintenance_manager.cc:419] P fe8fb96149534a8cb790a299863bb828: Scheduling FlushMRSOp(1bda84d5612240758cbca4bcb531ac15): perf score=1.000000
I20260812 06:17:51.767956 11565 maintenance_manager.cc:643] P fe8fb96149534a8cb790a299863bb828: FlushMRSOp(1bda84d5612240758cbca4bcb531ac15) complete. Timing: real 0.041s	user 0.028s	sys 0.000s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":70,"dirs.run_cpu_time_us":168,"dirs.run_wall_time_us":1727,"drs_written":1,"lbm_read_time_us":68,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1541,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:17:51.768786 11671 maintenance_manager.cc:419] P fe8fb96149534a8cb790a299863bb828: Scheduling LogGCOp(1bda84d5612240758cbca4bcb531ac15): free 128867483 bytes of WAL
I20260812 06:17:51.769032 11565 log_reader.cc:385] T 1bda84d5612240758cbca4bcb531ac15: removed 13 log segments from log reader
I20260812 06:17:51.769080 11565 log.cc:1079] T 1bda84d5612240758cbca4bcb531ac15 P fe8fb96149534a8cb790a299863bb828: Deleting log segment in path: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515468429503-11384-0/minicluster-data/ts-0-root/wals/1bda84d5612240758cbca4bcb531ac15/wal-000000015 (ops 72-76)
I20260812 06:17:51.769120 11565 log.cc:1079] T 1bda84d5612240758cbca4bcb531ac15 P fe8fb96149534a8cb790a299863bb828: Deleting log segment in path: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515468429503-11384-0/minicluster-data/ts-0-root/wals/1bda84d5612240758cbca4bcb531ac15/wal-000000016 (ops 77-81)
I20260812 06:17:51.769151 11565 log.cc:1079] T 1bda84d5612240758cbca4bcb531ac15 P fe8fb96149534a8cb790a299863bb828: Deleting log segment in path: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515468429503-11384-0/minicluster-data/ts-0-root/wals/1bda84d5612240758cbca4bcb531ac15/wal-000000017 (ops 82-86)
I20260812 06:17:51.769183 11565 log.cc:1079] T 1bda84d5612240758cbca4bcb531ac15 P fe8fb96149534a8cb790a299863bb828: Deleting log segment in path: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515468429503-11384-0/minicluster-data/ts-0-root/wals/1bda84d5612240758cbca4bcb531ac15/wal-000000018 (ops 87-91)
I20260812 06:17:51.769215 11565 log.cc:1079] T 1bda84d5612240758cbca4bcb531ac15 P fe8fb96149534a8cb790a299863bb828: Deleting log segment in path: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515468429503-11384-0/minicluster-data/ts-0-root/wals/1bda84d5612240758cbca4bcb531ac15/wal-000000019 (ops 92-96)
I20260812 06:17:51.769245 11565 log.cc:1079] T 1bda84d5612240758cbca4bcb531ac15 P fe8fb96149534a8cb790a299863bb828: Deleting log segment in path: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515468429503-11384-0/minicluster-data/ts-0-root/wals/1bda84d5612240758cbca4bcb531ac15/wal-000000020 (ops 97-100)
I20260812 06:17:51.769276 11565 log.cc:1079] T 1bda84d5612240758cbca4bcb531ac15 P fe8fb96149534a8cb790a299863bb828: Deleting log segment in path: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515468429503-11384-0/minicluster-data/ts-0-root/wals/1bda84d5612240758cbca4bcb531ac15/wal-000000021 (ops 101-105)
I20260812 06:17:51.769313 11565 log.cc:1079] T 1bda84d5612240758cbca4bcb531ac15 P fe8fb96149534a8cb790a299863bb828: Deleting log segment in path: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515468429503-11384-0/minicluster-data/ts-0-root/wals/1bda84d5612240758cbca4bcb531ac15/wal-000000022 (ops 106-110)
I20260812 06:17:51.769338 11565 log.cc:1079] T 1bda84d5612240758cbca4bcb531ac15 P fe8fb96149534a8cb790a299863bb828: Deleting log segment in path: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515468429503-11384-0/minicluster-data/ts-0-root/wals/1bda84d5612240758cbca4bcb531ac15/wal-000000023 (ops 111-114)
I20260812 06:17:51.769368 11565 log.cc:1079] T 1bda84d5612240758cbca4bcb531ac15 P fe8fb96149534a8cb790a299863bb828: Deleting log segment in path: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515468429503-11384-0/minicluster-data/ts-0-root/wals/1bda84d5612240758cbca4bcb531ac15/wal-000000024 (ops 115-119)
I20260812 06:17:51.769392 11565 log.cc:1079] T 1bda84d5612240758cbca4bcb531ac15 P fe8fb96149534a8cb790a299863bb828: Deleting log segment in path: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515468429503-11384-0/minicluster-data/ts-0-root/wals/1bda84d5612240758cbca4bcb531ac15/wal-000000025 (ops 120-124)
I20260812 06:17:51.769423 11565 log.cc:1079] T 1bda84d5612240758cbca4bcb531ac15 P fe8fb96149534a8cb790a299863bb828: Deleting log segment in path: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515468429503-11384-0/minicluster-data/ts-0-root/wals/1bda84d5612240758cbca4bcb531ac15/wal-000000026 (ops 125-128)
I20260812 06:17:51.769452 11565 log.cc:1079] T 1bda84d5612240758cbca4bcb531ac15 P fe8fb96149534a8cb790a299863bb828: Deleting log segment in path: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515468429503-11384-0/minicluster-data/ts-0-root/wals/1bda84d5612240758cbca4bcb531ac15/wal-000000027 (ops 129-133)
I20260812 06:17:51.792402 11565 maintenance_manager.cc:643] P fe8fb96149534a8cb790a299863bb828: LogGCOp(1bda84d5612240758cbca4bcb531ac15) complete. Timing: real 0.023s	user 0.000s	sys 0.021s Metrics: {}
I20260812 06:17:51.792920 11671 maintenance_manager.cc:419] P fe8fb96149534a8cb790a299863bb828: Scheduling UndoDeltaBlockGCOp(1bda84d5612240758cbca4bcb531ac15): 493 bytes on disk
I20260812 06:17:51.793362 11565 maintenance_manager.cc:643] P fe8fb96149534a8cb790a299863bb828: UndoDeltaBlockGCOp(1bda84d5612240758cbca4bcb531ac15) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4}
I20260812 06:17:51.794137 11671 maintenance_manager.cc:419] P fe8fb96149534a8cb790a299863bb828: Scheduling FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15): perf score=3.181125
I20260812 06:17:51.813397 11565 maintenance_manager.cc:643] P fe8fb96149534a8cb790a299863bb828: FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15) complete. Timing: real 0.019s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4120,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:51.813874 11671 maintenance_manager.cc:419] P fe8fb96149534a8cb790a299863bb828: Scheduling FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15): perf score=2.188937
I20260812 06:17:51.827502 11565 maintenance_manager.cc:643] P fe8fb96149534a8cb790a299863bb828: FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15) complete. Timing: real 0.013s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4899,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:51.828001 11671 maintenance_manager.cc:419] P fe8fb96149534a8cb790a299863bb828: Scheduling MajorDeltaCompactionOp(1bda84d5612240758cbca4bcb531ac15): perf score=1.000000
I20260812 06:17:52.047092 11565 maintenance_manager.cc:643] P fe8fb96149534a8cb790a299863bb828: MajorDeltaCompactionOp(1bda84d5612240758cbca4bcb531ac15) complete. Timing: real 0.219s	user 0.143s	sys 0.075s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32979851,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":297,"lbm_read_time_us":16654,"lbm_reads_lt_1ms":775,"lbm_write_time_us":36796,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":1536,"thread_start_us":86,"threads_started":1,"update_count":3500}
I20260812 06:17:52.047645 11671 maintenance_manager.cc:419] P fe8fb96149534a8cb790a299863bb828: Scheduling FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15): perf score=14.095187
I20260812 06:17:52.096078 11565 maintenance_manager.cc:643] P fe8fb96149534a8cb790a299863bb828: FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15) complete. Timing: real 0.046s	user 0.022s	sys 0.022s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20566,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:52.096742 11671 maintenance_manager.cc:419] P fe8fb96149534a8cb790a299863bb828: Scheduling FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15): perf score=2.188937
I20260812 06:17:52.114709 11565 maintenance_manager.cc:643] P fe8fb96149534a8cb790a299863bb828: FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15) complete. Timing: real 0.018s	user 0.006s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":7419,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":102,"reinsert_count":0,"update_count":500}
I20260812 06:17:52.115166 11671 maintenance_manager.cc:419] P fe8fb96149534a8cb790a299863bb828: Scheduling MajorDeltaCompactionOp(1bda84d5612240758cbca4bcb531ac15): perf score=1.000000
I20260812 06:17:52.289886 11565 maintenance_manager.cc:643] P fe8fb96149534a8cb790a299863bb828: MajorDeltaCompactionOp(1bda84d5612240758cbca4bcb531ac15) complete. Timing: real 0.175s	user 0.115s	sys 0.056s 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":637,"lbm_read_time_us":12343,"lbm_reads_lt_1ms":564,"lbm_write_time_us":29747,"lbm_writes_lt_1ms":543,"mutex_wait_us":313,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":19840,"update_count":2500}
I20260812 06:17:52.290632 11671 maintenance_manager.cc:419] P fe8fb96149534a8cb790a299863bb828: Scheduling FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15): perf score=14.095187
I20260812 06:17:52.339001 11565 maintenance_manager.cc:643] P fe8fb96149534a8cb790a299863bb828: FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15) complete. Timing: real 0.048s	user 0.022s	sys 0.019s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":18616,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:52.339445 11671 maintenance_manager.cc:419] P fe8fb96149534a8cb790a299863bb828: Scheduling FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15): perf score=3.181125
I20260812 06:17:52.361734 11565 maintenance_manager.cc:643] P fe8fb96149534a8cb790a299863bb828: FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15) complete. Timing: real 0.022s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4370,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:52.362174 11671 maintenance_manager.cc:419] P fe8fb96149534a8cb790a299863bb828: Scheduling FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15): perf score=2.188937
I20260812 06:17:52.371687 11565 maintenance_manager.cc:643] P fe8fb96149534a8cb790a299863bb828: FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15) complete. Timing: real 0.009s	user 0.004s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3611,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:52.372097 11671 maintenance_manager.cc:419] P fe8fb96149534a8cb790a299863bb828: Scheduling MajorDeltaCompactionOp(1bda84d5612240758cbca4bcb531ac15): perf score=1.000000
I20260812 06:17:52.557579 11565 maintenance_manager.cc:643] P fe8fb96149534a8cb790a299863bb828: MajorDeltaCompactionOp(1bda84d5612240758cbca4bcb531ac15) complete. Timing: real 0.185s	user 0.130s	sys 0.055s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877213,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":865,"lbm_read_time_us":11767,"lbm_reads_lt_1ms":673,"lbm_write_time_us":32452,"lbm_writes_lt_1ms":643,"mutex_wait_us":78,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":3000}
I20260812 06:17:52.558171 11671 maintenance_manager.cc:419] P fe8fb96149534a8cb790a299863bb828: Scheduling FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15): perf score=14.095187
I20260812 06:17:52.612149 11565 maintenance_manager.cc:643] P fe8fb96149534a8cb790a299863bb828: FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15) complete. Timing: real 0.054s	user 0.017s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":17720,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:52.612715 11671 maintenance_manager.cc:419] P fe8fb96149534a8cb790a299863bb828: Scheduling FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15): perf score=2.188937
I20260812 06:17:52.623606 11565 maintenance_manager.cc:643] P fe8fb96149534a8cb790a299863bb828: FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3727,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:52.624209 11671 maintenance_manager.cc:419] P fe8fb96149534a8cb790a299863bb828: Scheduling MajorDeltaCompactionOp(1bda84d5612240758cbca4bcb531ac15): perf score=1.000000
I20260812 06:17:52.786235 11565 maintenance_manager.cc:643] P fe8fb96149534a8cb790a299863bb828: MajorDeltaCompactionOp(1bda84d5612240758cbca4bcb531ac15) complete. Timing: real 0.162s	user 0.115s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":804,"lbm_read_time_us":11024,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25635,"lbm_writes_lt_1ms":543,"mutex_wait_us":242,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7296,"update_count":2500}
I20260812 06:17:52.786787 11671 maintenance_manager.cc:419] P fe8fb96149534a8cb790a299863bb828: Scheduling FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15): perf score=14.095187
I20260812 06:17:52.842059 11565 maintenance_manager.cc:643] P fe8fb96149534a8cb790a299863bb828: FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15) complete. Timing: real 0.055s	user 0.026s	sys 0.027s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":23958,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":400,"reinsert_count":0,"update_count":2000}
I20260812 06:17:52.842569 11671 maintenance_manager.cc:419] P fe8fb96149534a8cb790a299863bb828: Scheduling FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15): perf score=2.188937
I20260812 06:17:52.853596 11565 maintenance_manager.cc:643] P fe8fb96149534a8cb790a299863bb828: FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15) complete. Timing: real 0.011s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3996,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:52.854071 11671 maintenance_manager.cc:419] P fe8fb96149534a8cb790a299863bb828: Scheduling MajorDeltaCompactionOp(1bda84d5612240758cbca4bcb531ac15): perf score=1.000000
I20260812 06:17:53.030017 11565 maintenance_manager.cc:643] P fe8fb96149534a8cb790a299863bb828: MajorDeltaCompactionOp(1bda84d5612240758cbca4bcb531ac15) complete. Timing: real 0.176s	user 0.117s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774692,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":556,"lbm_read_time_us":11878,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28380,"lbm_writes_lt_1ms":543,"mutex_wait_us":22,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8960,"update_count":2500}
I20260812 06:17:53.030488 11671 maintenance_manager.cc:419] P fe8fb96149534a8cb790a299863bb828: Scheduling FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15): perf score=14.095187
I20260812 06:17:53.099615 11565 maintenance_manager.cc:643] P fe8fb96149534a8cb790a299863bb828: FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15) complete. Timing: real 0.069s	user 0.032s	sys 0.035s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":27056,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:53.100296 11671 maintenance_manager.cc:419] P fe8fb96149534a8cb790a299863bb828: Scheduling FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15): perf score=2.188937
I20260812 06:17:53.113739 11565 maintenance_manager.cc:643] P fe8fb96149534a8cb790a299863bb828: FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15) complete. Timing: real 0.013s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5077,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:53.114342 11671 maintenance_manager.cc:419] P fe8fb96149534a8cb790a299863bb828: Scheduling FlushMRSOp(1bda84d5612240758cbca4bcb531ac15): perf score=1.000000
I20260812 06:17:53.143520 11565 maintenance_manager.cc:643] P fe8fb96149534a8cb790a299863bb828: FlushMRSOp(1bda84d5612240758cbca4bcb531ac15) complete. Timing: real 0.029s	user 0.022s	sys 0.003s Metrics: {"bytes_written":1152512,"cfile_init":1,"dirs.queue_time_us":67,"dirs.run_cpu_time_us":250,"dirs.run_wall_time_us":1281,"drs_written":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1496,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:17:53.144218 11671 maintenance_manager.cc:419] P fe8fb96149534a8cb790a299863bb828: Scheduling LogGCOp(1bda84d5612240758cbca4bcb531ac15): free 120553584 bytes of WAL
I20260812 06:17:53.144434 11565 log_reader.cc:385] T 1bda84d5612240758cbca4bcb531ac15: removed 12 log segments from log reader
I20260812 06:17:53.144481 11565 log.cc:1079] T 1bda84d5612240758cbca4bcb531ac15 P fe8fb96149534a8cb790a299863bb828: Deleting log segment in path: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515468429503-11384-0/minicluster-data/ts-0-root/wals/1bda84d5612240758cbca4bcb531ac15/wal-000000028 (ops 134-138)
I20260812 06:17:53.144516 11565 log.cc:1079] T 1bda84d5612240758cbca4bcb531ac15 P fe8fb96149534a8cb790a299863bb828: Deleting log segment in path: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515468429503-11384-0/minicluster-data/ts-0-root/wals/1bda84d5612240758cbca4bcb531ac15/wal-000000029 (ops 139-142)
I20260812 06:17:53.144556 11565 log.cc:1079] T 1bda84d5612240758cbca4bcb531ac15 P fe8fb96149534a8cb790a299863bb828: Deleting log segment in path: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515468429503-11384-0/minicluster-data/ts-0-root/wals/1bda84d5612240758cbca4bcb531ac15/wal-000000030 (ops 143-147)
I20260812 06:17:53.144593 11565 log.cc:1079] T 1bda84d5612240758cbca4bcb531ac15 P fe8fb96149534a8cb790a299863bb828: Deleting log segment in path: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515468429503-11384-0/minicluster-data/ts-0-root/wals/1bda84d5612240758cbca4bcb531ac15/wal-000000031 (ops 148-152)
I20260812 06:17:53.144632 11565 log.cc:1079] T 1bda84d5612240758cbca4bcb531ac15 P fe8fb96149534a8cb790a299863bb828: Deleting log segment in path: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515468429503-11384-0/minicluster-data/ts-0-root/wals/1bda84d5612240758cbca4bcb531ac15/wal-000000032 (ops 153-157)
I20260812 06:17:53.144670 11565 log.cc:1079] T 1bda84d5612240758cbca4bcb531ac15 P fe8fb96149534a8cb790a299863bb828: Deleting log segment in path: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515468429503-11384-0/minicluster-data/ts-0-root/wals/1bda84d5612240758cbca4bcb531ac15/wal-000000033 (ops 158-162)
I20260812 06:17:53.144708 11565 log.cc:1079] T 1bda84d5612240758cbca4bcb531ac15 P fe8fb96149534a8cb790a299863bb828: Deleting log segment in path: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515468429503-11384-0/minicluster-data/ts-0-root/wals/1bda84d5612240758cbca4bcb531ac15/wal-000000034 (ops 163-166)
I20260812 06:17:53.144747 11565 log.cc:1079] T 1bda84d5612240758cbca4bcb531ac15 P fe8fb96149534a8cb790a299863bb828: Deleting log segment in path: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515468429503-11384-0/minicluster-data/ts-0-root/wals/1bda84d5612240758cbca4bcb531ac15/wal-000000035 (ops 167-171)
I20260812 06:17:53.144784 11565 log.cc:1079] T 1bda84d5612240758cbca4bcb531ac15 P fe8fb96149534a8cb790a299863bb828: Deleting log segment in path: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515468429503-11384-0/minicluster-data/ts-0-root/wals/1bda84d5612240758cbca4bcb531ac15/wal-000000036 (ops 172-176)
I20260812 06:17:53.144822 11565 log.cc:1079] T 1bda84d5612240758cbca4bcb531ac15 P fe8fb96149534a8cb790a299863bb828: Deleting log segment in path: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515468429503-11384-0/minicluster-data/ts-0-root/wals/1bda84d5612240758cbca4bcb531ac15/wal-000000037 (ops 177-181)
I20260812 06:17:53.144860 11565 log.cc:1079] T 1bda84d5612240758cbca4bcb531ac15 P fe8fb96149534a8cb790a299863bb828: Deleting log segment in path: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515468429503-11384-0/minicluster-data/ts-0-root/wals/1bda84d5612240758cbca4bcb531ac15/wal-000000038 (ops 182-186)
I20260812 06:17:53.144898 11565 log.cc:1079] T 1bda84d5612240758cbca4bcb531ac15 P fe8fb96149534a8cb790a299863bb828: Deleting log segment in path: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515468429503-11384-0/minicluster-data/ts-0-root/wals/1bda84d5612240758cbca4bcb531ac15/wal-000000039 (ops 187-191)
I20260812 06:17:53.166328 11565 maintenance_manager.cc:643] P fe8fb96149534a8cb790a299863bb828: LogGCOp(1bda84d5612240758cbca4bcb531ac15) complete. Timing: real 0.022s	user 0.000s	sys 0.021s Metrics: {}
I20260812 06:17:53.166729 11671 maintenance_manager.cc:419] P fe8fb96149534a8cb790a299863bb828: Scheduling FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15): perf score=3.181125
I20260812 06:17:53.190399 11565 maintenance_manager.cc:643] P fe8fb96149534a8cb790a299863bb828: FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15) complete. Timing: real 0.023s	user 0.005s	sys 0.009s Metrics: {"bytes_written":4512904,"delete_count":0,"lbm_write_time_us":5991,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:53.190867 11671 maintenance_manager.cc:419] P fe8fb96149534a8cb790a299863bb828: Scheduling UndoDeltaBlockGCOp(1bda84d5612240758cbca4bcb531ac15): 447 bytes on disk
I20260812 06:17:53.191313 11565 maintenance_manager.cc:643] P fe8fb96149534a8cb790a299863bb828: UndoDeltaBlockGCOp(1bda84d5612240758cbca4bcb531ac15) 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:17:53.191855 11671 maintenance_manager.cc:419] P fe8fb96149534a8cb790a299863bb828: Scheduling FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15): perf score=2.188937
I20260812 06:17:53.205634 11565 maintenance_manager.cc:643] P fe8fb96149534a8cb790a299863bb828: FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15) complete. Timing: real 0.014s	user 0.006s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4891,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:53.206132 11671 maintenance_manager.cc:419] P fe8fb96149534a8cb790a299863bb828: Scheduling MajorDeltaCompactionOp(1bda84d5612240758cbca4bcb531ac15): perf score=1.000000
I20260812 06:17:53.380092 11384 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.672s	user 1.708s	sys 0.129s
I20260812 06:17:53.413127 11565 maintenance_manager.cc:643] P fe8fb96149534a8cb790a299863bb828: MajorDeltaCompactionOp(1bda84d5612240758cbca4bcb531ac15) complete. Timing: real 0.207s	user 0.140s	sys 0.063s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979741,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"lbm_read_time_us":15652,"lbm_reads_lt_1ms":770,"lbm_write_time_us":33466,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":3200,"update_count":3500}
I20260812 06:17:53.413708 11671 maintenance_manager.cc:419] P fe8fb96149534a8cb790a299863bb828: Scheduling FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15): perf score=14.095187
I20260812 06:17:53.444594 11565 maintenance_manager.cc:643] P fe8fb96149534a8cb790a299863bb828: FlushDeltaMemStoresOp(1bda84d5612240758cbca4bcb531ac15) complete. Timing: real 0.031s	user 0.013s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":14545,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:53.445043 11671 maintenance_manager.cc:419] P fe8fb96149534a8cb790a299863bb828: Scheduling MajorDeltaCompactionOp(1bda84d5612240758cbca4bcb531ac15): perf score=1.000000
I20260812 06:17:53.477193 11384 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.097s	user 0.002s	sys 0.000s
I20260812 06:17:53.477972 11384 tablet_server.cc:179] TabletServer@127.11.30.1:0 shutting down...
I20260812 06:17:53.567387 11565 maintenance_manager.cc:643] P fe8fb96149534a8cb790a299863bb828: MajorDeltaCompactionOp(1bda84d5612240758cbca4bcb531ac15) complete. Timing: real 0.122s	user 0.068s	sys 0.052s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672158,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":321,"lbm_read_time_us":9564,"lbm_reads_lt_1ms":467,"lbm_write_time_us":24176,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":442,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:53.568403 11384 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:53.568823 11384 tablet_replica.cc:333] T 1bda84d5612240758cbca4bcb531ac15 P fe8fb96149534a8cb790a299863bb828: stopping tablet replica
I20260812 06:17:53.569058 11384 raft_consensus.cc:2243] T 1bda84d5612240758cbca4bcb531ac15 P fe8fb96149534a8cb790a299863bb828 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:53.569291 11384 raft_consensus.cc:2272] T 1bda84d5612240758cbca4bcb531ac15 P fe8fb96149534a8cb790a299863bb828 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:53.585562 11384 tablet_server.cc:196] TabletServer@127.11.30.1:0 shutdown complete.
I20260812 06:17:53.605660 11384 master.cc:562] Master@127.11.30.62:35531 shutting down...
I20260812 06:17:53.608877 11384 raft_consensus.cc:2243] T 00000000000000000000000000000000 P efbc8f8e91fd4552a76758aba858118e [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:53.609043 11384 raft_consensus.cc:2272] T 00000000000000000000000000000000 P efbc8f8e91fd4552a76758aba858118e [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:53.609098 11384 tablet_replica.cc:333] T 00000000000000000000000000000000 P efbc8f8e91fd4552a76758aba858118e: stopping tablet replica
I20260812 06:17:53.621120 11384 master.cc:584] Master@127.11.30.62:35531 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5255 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:17:53.695276 11384 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.11.30.62:38153
I20260812 06:17:53.695653 11384 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:53.697455 11738 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:53.697508 11729 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:53.697652 11731 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:53.697899 11384 server_base.cc:1061] running on GCE node
I20260812 06:17:53.698086 11384 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:53.698125 11384 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:53.698140 11384 hybrid_clock.cc:648] HybridClock initialized: now 1786515473698140 us; error 0 us; skew 500 ppm
I20260812 06:17:53.698992 11384 webserver.cc:533] Webserver started at http://127.11.30.62:46167/ using document root <none> and password file <none>
I20260812 06:17:53.699149 11384 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:53.699198 11384 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:53.699270 11384 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:53.699625 11384 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515468429503-11384-0/minicluster-data/master-0-root/instance:
uuid: "a46f99160da042fc98d42bd0c72926f4"
format_stamp: "Formatted at 2026-08-12 06:17:53 on dist-test-slave-7lbf"
I20260812 06:17:53.701018 11384 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:17:53.701979 11746 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:53.702219 11384 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.000s
I20260812 06:17:53.702289 11384 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515468429503-11384-0/minicluster-data/master-0-root
uuid: "a46f99160da042fc98d42bd0c72926f4"
format_stamp: "Formatted at 2026-08-12 06:17:53 on dist-test-slave-7lbf"
I20260812 06:17:53.702358 11384 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515468429503-11384-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515468429503-11384-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515468429503-11384-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:53.720300 11384 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:53.720659 11384 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:53.724577 11384 rpc_server.cc:307] RPC server started. Bound to: 127.11.30.62:38153
I20260812 06:17:53.738798 11841 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.11.30.62:38153 every 8 connection(s)
I20260812 06:17:53.739275 11842 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:53.741065 11842 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P a46f99160da042fc98d42bd0c72926f4: Bootstrap starting.
I20260812 06:17:53.741879 11842 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P a46f99160da042fc98d42bd0c72926f4: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:53.742818 11842 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P a46f99160da042fc98d42bd0c72926f4: No bootstrap required, opened a new log
I20260812 06:17:53.743196 11842 raft_consensus.cc:359] T 00000000000000000000000000000000 P a46f99160da042fc98d42bd0c72926f4 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a46f99160da042fc98d42bd0c72926f4" member_type: VOTER }
I20260812 06:17:53.743319 11842 raft_consensus.cc:385] T 00000000000000000000000000000000 P a46f99160da042fc98d42bd0c72926f4 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:53.743351 11842 raft_consensus.cc:740] T 00000000000000000000000000000000 P a46f99160da042fc98d42bd0c72926f4 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: a46f99160da042fc98d42bd0c72926f4, State: Initialized, Role: FOLLOWER
I20260812 06:17:53.743501 11842 consensus_queue.cc:260] T 00000000000000000000000000000000 P a46f99160da042fc98d42bd0c72926f4 [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: "a46f99160da042fc98d42bd0c72926f4" member_type: VOTER }
I20260812 06:17:53.743574 11842 raft_consensus.cc:399] T 00000000000000000000000000000000 P a46f99160da042fc98d42bd0c72926f4 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:53.743608 11842 raft_consensus.cc:493] T 00000000000000000000000000000000 P a46f99160da042fc98d42bd0c72926f4 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:53.743655 11842 raft_consensus.cc:3060] T 00000000000000000000000000000000 P a46f99160da042fc98d42bd0c72926f4 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:53.744288 11842 raft_consensus.cc:515] T 00000000000000000000000000000000 P a46f99160da042fc98d42bd0c72926f4 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a46f99160da042fc98d42bd0c72926f4" member_type: VOTER }
I20260812 06:17:53.744400 11842 leader_election.cc:304] T 00000000000000000000000000000000 P a46f99160da042fc98d42bd0c72926f4 [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: a46f99160da042fc98d42bd0c72926f4; no voters: 
I20260812 06:17:53.744585 11842 leader_election.cc:290] T 00000000000000000000000000000000 P a46f99160da042fc98d42bd0c72926f4 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:53.744711 11851 raft_consensus.cc:2804] T 00000000000000000000000000000000 P a46f99160da042fc98d42bd0c72926f4 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:53.744901 11851 raft_consensus.cc:697] T 00000000000000000000000000000000 P a46f99160da042fc98d42bd0c72926f4 [term 1 LEADER]: Becoming Leader. State: Replica: a46f99160da042fc98d42bd0c72926f4, State: Running, Role: LEADER
I20260812 06:17:53.745038 11851 consensus_queue.cc:237] T 00000000000000000000000000000000 P a46f99160da042fc98d42bd0c72926f4 [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: "a46f99160da042fc98d42bd0c72926f4" member_type: VOTER }
I20260812 06:17:53.745112 11842 sys_catalog.cc:565] T 00000000000000000000000000000000 P a46f99160da042fc98d42bd0c72926f4 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:53.745428 11853 sys_catalog.cc:455] T 00000000000000000000000000000000 P a46f99160da042fc98d42bd0c72926f4 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "a46f99160da042fc98d42bd0c72926f4" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a46f99160da042fc98d42bd0c72926f4" member_type: VOTER } }
I20260812 06:17:53.745550 11853 sys_catalog.cc:458] T 00000000000000000000000000000000 P a46f99160da042fc98d42bd0c72926f4 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:53.745445 11855 sys_catalog.cc:455] T 00000000000000000000000000000000 P a46f99160da042fc98d42bd0c72926f4 [sys.catalog]: SysCatalogTable state changed. Reason: New leader a46f99160da042fc98d42bd0c72926f4. Latest consensus state: current_term: 1 leader_uuid: "a46f99160da042fc98d42bd0c72926f4" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a46f99160da042fc98d42bd0c72926f4" member_type: VOTER } }
I20260812 06:17:53.745787 11855 sys_catalog.cc:458] T 00000000000000000000000000000000 P a46f99160da042fc98d42bd0c72926f4 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:53.745868 11859 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:53.746557 11859 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:53.746881 11384 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:53.748257 11859 catalog_manager.cc:1383] Generated new cluster ID: bc6ab2fad38440ce9426a45bc1aaee71
I20260812 06:17:53.748301 11859 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:53.755420 11859 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:53.755920 11859 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:53.760649 11859 catalog_manager.cc:6092] T 00000000000000000000000000000000 P a46f99160da042fc98d42bd0c72926f4: Generated new TSK 0
I20260812 06:17:53.760799 11859 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:53.762938 11384 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:53.764698 11883 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:53.764763 11884 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:53.764840 11384 server_base.cc:1061] running on GCE node
W20260812 06:17:53.764999 11887 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:53.765198 11384 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:53.765244 11384 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:53.765257 11384 hybrid_clock.cc:648] HybridClock initialized: now 1786515473765258 us; error 0 us; skew 500 ppm
I20260812 06:17:53.766163 11384 webserver.cc:533] Webserver started at http://127.11.30.1:43721/ using document root <none> and password file <none>
I20260812 06:17:53.766330 11384 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:53.766402 11384 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:53.766480 11384 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:53.766942 11384 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515468429503-11384-0/minicluster-data/ts-0-root/instance:
uuid: "d3856062b71a4d95a61f2eb437c90aaa"
format_stamp: "Formatted at 2026-08-12 06:17:53 on dist-test-slave-7lbf"
I20260812 06:17:53.768335 11384 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:17:53.769186 11894 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:53.769419 11384 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:53.769485 11384 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515468429503-11384-0/minicluster-data/ts-0-root
uuid: "d3856062b71a4d95a61f2eb437c90aaa"
format_stamp: "Formatted at 2026-08-12 06:17:53 on dist-test-slave-7lbf"
I20260812 06:17:53.769567 11384 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515468429503-11384-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515468429503-11384-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515468429503-11384-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:53.775769 11384 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:53.776077 11384 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:53.776336 11384 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:53.776786 11384 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:53.776822 11384 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:53.776865 11384 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:53.776901 11384 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:53.780817 11384 rpc_server.cc:307] RPC server started. Bound to: 127.11.30.1:41825
I20260812 06:17:53.780840 12005 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.11.30.1:41825 every 8 connection(s)
I20260812 06:17:53.787837 12006 heartbeater.cc:344] Connected to a master server at 127.11.30.62:38153
I20260812 06:17:53.787930 12006 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:53.788131 12006 heartbeater.cc:507] Master 127.11.30.62:38153 requested a full tablet report, sending...
I20260812 06:17:53.788723 11775 ts_manager.cc:194] Registered new tserver with Master: d3856062b71a4d95a61f2eb437c90aaa (127.11.30.1:41825)
I20260812 06:17:53.788857 11384 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.00768179s
I20260812 06:17:53.789713 11775 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:55158
I20260812 06:17:53.795331 11775 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:55166:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:17:53.803581 11939 tablet_service.cc:1511] Processing CreateTablet for tablet a51c85635a24499987232b018791a2a5 (DEFAULT_TABLE table=heavy-update-compaction-test [id=8304ee539cc146b8af3fa823601b1ea4]), partition=
I20260812 06:17:53.803826 11939 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet a51c85635a24499987232b018791a2a5. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:53.805642 12030 tablet_bootstrap.cc:492] T a51c85635a24499987232b018791a2a5 P d3856062b71a4d95a61f2eb437c90aaa: Bootstrap starting.
I20260812 06:17:53.806576 12030 tablet_bootstrap.cc:654] T a51c85635a24499987232b018791a2a5 P d3856062b71a4d95a61f2eb437c90aaa: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:53.807523 12030 tablet_bootstrap.cc:492] T a51c85635a24499987232b018791a2a5 P d3856062b71a4d95a61f2eb437c90aaa: No bootstrap required, opened a new log
I20260812 06:17:53.807595 12030 ts_tablet_manager.cc:1403] T a51c85635a24499987232b018791a2a5 P d3856062b71a4d95a61f2eb437c90aaa: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:17:53.807942 12030 raft_consensus.cc:359] T a51c85635a24499987232b018791a2a5 P d3856062b71a4d95a61f2eb437c90aaa [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d3856062b71a4d95a61f2eb437c90aaa" member_type: VOTER last_known_addr { host: "127.11.30.1" port: 41825 } }
I20260812 06:17:53.808024 12030 raft_consensus.cc:385] T a51c85635a24499987232b018791a2a5 P d3856062b71a4d95a61f2eb437c90aaa [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:53.808051 12030 raft_consensus.cc:740] T a51c85635a24499987232b018791a2a5 P d3856062b71a4d95a61f2eb437c90aaa [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: d3856062b71a4d95a61f2eb437c90aaa, State: Initialized, Role: FOLLOWER
I20260812 06:17:53.808141 12030 consensus_queue.cc:260] T a51c85635a24499987232b018791a2a5 P d3856062b71a4d95a61f2eb437c90aaa [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: "d3856062b71a4d95a61f2eb437c90aaa" member_type: VOTER last_known_addr { host: "127.11.30.1" port: 41825 } }
I20260812 06:17:53.808198 12030 raft_consensus.cc:399] T a51c85635a24499987232b018791a2a5 P d3856062b71a4d95a61f2eb437c90aaa [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:53.808224 12030 raft_consensus.cc:493] T a51c85635a24499987232b018791a2a5 P d3856062b71a4d95a61f2eb437c90aaa [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:53.808256 12030 raft_consensus.cc:3060] T a51c85635a24499987232b018791a2a5 P d3856062b71a4d95a61f2eb437c90aaa [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:53.809033 12030 raft_consensus.cc:515] T a51c85635a24499987232b018791a2a5 P d3856062b71a4d95a61f2eb437c90aaa [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d3856062b71a4d95a61f2eb437c90aaa" member_type: VOTER last_known_addr { host: "127.11.30.1" port: 41825 } }
I20260812 06:17:53.809175 12030 leader_election.cc:304] T a51c85635a24499987232b018791a2a5 P d3856062b71a4d95a61f2eb437c90aaa [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: d3856062b71a4d95a61f2eb437c90aaa; no voters: 
I20260812 06:17:53.809358 12030 leader_election.cc:290] T a51c85635a24499987232b018791a2a5 P d3856062b71a4d95a61f2eb437c90aaa [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:53.809454 12032 raft_consensus.cc:2804] T a51c85635a24499987232b018791a2a5 P d3856062b71a4d95a61f2eb437c90aaa [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:53.809666 12030 ts_tablet_manager.cc:1434] T a51c85635a24499987232b018791a2a5 P d3856062b71a4d95a61f2eb437c90aaa: Time spent starting tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:53.809676 12032 raft_consensus.cc:697] T a51c85635a24499987232b018791a2a5 P d3856062b71a4d95a61f2eb437c90aaa [term 1 LEADER]: Becoming Leader. State: Replica: d3856062b71a4d95a61f2eb437c90aaa, State: Running, Role: LEADER
I20260812 06:17:53.809743 12006 heartbeater.cc:499] Master 127.11.30.62:38153 was elected leader, sending a full tablet report...
I20260812 06:17:53.809877 12032 consensus_queue.cc:237] T a51c85635a24499987232b018791a2a5 P d3856062b71a4d95a61f2eb437c90aaa [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: "d3856062b71a4d95a61f2eb437c90aaa" member_type: VOTER last_known_addr { host: "127.11.30.1" port: 41825 } }
I20260812 06:17:53.811105 11775 catalog_manager.cc:5719] T a51c85635a24499987232b018791a2a5 P d3856062b71a4d95a61f2eb437c90aaa reported cstate change: term changed from 0 to 1, leader changed from <none> to d3856062b71a4d95a61f2eb437c90aaa (127.11.30.1). New cstate: current_term: 1 leader_uuid: "d3856062b71a4d95a61f2eb437c90aaa" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d3856062b71a4d95a61f2eb437c90aaa" member_type: VOTER last_known_addr { host: "127.11.30.1" port: 41825 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:53.864795 11384 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.050s	user 0.013s	sys 0.008s
I20260812 06:17:54.031733 12007 maintenance_manager.cc:419] P d3856062b71a4d95a61f2eb437c90aaa: Scheduling FlushMRSOp(a51c85635a24499987232b018791a2a5): perf score=23.023690
I20260812 06:17:54.196205 11900 maintenance_manager.cc:643] P d3856062b71a4d95a61f2eb437c90aaa: FlushMRSOp(a51c85635a24499987232b018791a2a5) complete. Timing: real 0.164s	user 0.116s	sys 0.045s Metrics: {"bytes_written":12389539,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":67,"dirs.run_cpu_time_us":190,"dirs.run_wall_time_us":736,"drs_written":1,"lbm_read_time_us":51,"lbm_reads_lt_1ms":4,"lbm_write_time_us":44859,"lbm_writes_lt_1ms":859,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"spinlock_wait_cycles":13696,"update_count":1510}
I20260812 06:17:54.196955 12007 maintenance_manager.cc:419] P d3856062b71a4d95a61f2eb437c90aaa: Scheduling LogGCOp(a51c85635a24499987232b018791a2a5): free 20743880 bytes of WAL
I20260812 06:17:54.197196 11900 log_reader.cc:385] T a51c85635a24499987232b018791a2a5: removed 2 log segments from log reader
I20260812 06:17:54.197247 11900 log.cc:1079] T a51c85635a24499987232b018791a2a5 P d3856062b71a4d95a61f2eb437c90aaa: Deleting log segment in path: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515468429503-11384-0/minicluster-data/ts-0-root/wals/a51c85635a24499987232b018791a2a5/wal-000000001 (ops 1-6)
I20260812 06:17:54.197279 11900 log.cc:1079] T a51c85635a24499987232b018791a2a5 P d3856062b71a4d95a61f2eb437c90aaa: Deleting log segment in path: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515468429503-11384-0/minicluster-data/ts-0-root/wals/a51c85635a24499987232b018791a2a5/wal-000000002 (ops 7-11)
I20260812 06:17:54.200908 11900 maintenance_manager.cc:643] P d3856062b71a4d95a61f2eb437c90aaa: LogGCOp(a51c85635a24499987232b018791a2a5) complete. Timing: real 0.004s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:17:54.201287 12007 maintenance_manager.cc:419] P d3856062b71a4d95a61f2eb437c90aaa: Scheduling UndoDeltaBlockGCOp(a51c85635a24499987232b018791a2a5): 20513813 bytes on disk
I20260812 06:17:54.201820 11900 maintenance_manager.cc:643] P d3856062b71a4d95a61f2eb437c90aaa: UndoDeltaBlockGCOp(a51c85635a24499987232b018791a2a5) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":75,"lbm_reads_lt_1ms":4}
I20260812 06:17:54.202339 12007 maintenance_manager.cc:419] P d3856062b71a4d95a61f2eb437c90aaa: Scheduling FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5): perf score=2.188937
I20260812 06:17:54.219123 11900 maintenance_manager.cc:643] P d3856062b71a4d95a61f2eb437c90aaa: FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5) complete. Timing: real 0.017s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4020609,"delete_count":0,"lbm_write_time_us":5941,"lbm_writes_lt_1ms":101,"reinsert_count":0,"update_count":490}
I20260812 06:17:54.219660 12007 maintenance_manager.cc:419] P d3856062b71a4d95a61f2eb437c90aaa: Scheduling MajorDeltaCompactionOp(a51c85635a24499987232b018791a2a5): perf score=1.000000
I20260812 06:17:54.391719 11900 maintenance_manager.cc:643] P d3856062b71a4d95a61f2eb437c90aaa: MajorDeltaCompactionOp(a51c85635a24499987232b018791a2a5) complete. Timing: real 0.172s	user 0.096s	sys 0.063s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713271,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":444,"lbm_read_time_us":11204,"lbm_reads_lt_1ms":460,"lbm_write_time_us":23580,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1792,"thread_start_us":332,"threads_started":5,"update_count":2000}
I20260812 06:17:54.392187 12007 maintenance_manager.cc:419] P d3856062b71a4d95a61f2eb437c90aaa: Scheduling FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5): perf score=14.095187
I20260812 06:17:54.439815 11900 maintenance_manager.cc:643] P d3856062b71a4d95a61f2eb437c90aaa: FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5) complete. Timing: real 0.047s	user 0.034s	sys 0.008s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19435,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:54.440245 12007 maintenance_manager.cc:419] P d3856062b71a4d95a61f2eb437c90aaa: Scheduling FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5): perf score=2.188937
I20260812 06:17:54.450256 11900 maintenance_manager.cc:643] P d3856062b71a4d95a61f2eb437c90aaa: FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3761,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:54.450714 12007 maintenance_manager.cc:419] P d3856062b71a4d95a61f2eb437c90aaa: Scheduling MajorDeltaCompactionOp(a51c85635a24499987232b018791a2a5): perf score=1.000000
I20260812 06:17:54.593245 11900 maintenance_manager.cc:643] P d3856062b71a4d95a61f2eb437c90aaa: MajorDeltaCompactionOp(a51c85635a24499987232b018791a2a5) complete. Timing: real 0.142s	user 0.102s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":191,"lbm_read_time_us":10095,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27063,"lbm_writes_lt_1ms":543,"mutex_wait_us":38,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":37760,"update_count":2500}
I20260812 06:17:54.593791 12007 maintenance_manager.cc:419] P d3856062b71a4d95a61f2eb437c90aaa: Scheduling FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5): perf score=10.126437
I20260812 06:17:54.628940 11900 maintenance_manager.cc:643] P d3856062b71a4d95a61f2eb437c90aaa: FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5) complete. Timing: real 0.035s	user 0.021s	sys 0.011s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15011,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:54.629494 12007 maintenance_manager.cc:419] P d3856062b71a4d95a61f2eb437c90aaa: Scheduling FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5): perf score=2.188937
I20260812 06:17:54.651701 11900 maintenance_manager.cc:643] P d3856062b71a4d95a61f2eb437c90aaa: FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5) complete. Timing: real 0.022s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5655,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:54.652159 12007 maintenance_manager.cc:419] P d3856062b71a4d95a61f2eb437c90aaa: Scheduling MajorDeltaCompactionOp(a51c85635a24499987232b018791a2a5): perf score=1.000000
I20260812 06:17:54.775174 11900 maintenance_manager.cc:643] P d3856062b71a4d95a61f2eb437c90aaa: MajorDeltaCompactionOp(a51c85635a24499987232b018791a2a5) complete. Timing: real 0.123s	user 0.111s	sys 0.012s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713273,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":519,"lbm_read_time_us":8908,"lbm_reads_lt_1ms":464,"lbm_write_time_us":22265,"lbm_writes_lt_1ms":443,"mutex_wait_us":294,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":24064,"update_count":2000}
I20260812 06:17:54.775717 12007 maintenance_manager.cc:419] P d3856062b71a4d95a61f2eb437c90aaa: Scheduling FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5): perf score=10.126437
I20260812 06:17:54.810549 11900 maintenance_manager.cc:643] P d3856062b71a4d95a61f2eb437c90aaa: FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5) complete. Timing: real 0.035s	user 0.017s	sys 0.015s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":14409,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:54.811034 12007 maintenance_manager.cc:419] P d3856062b71a4d95a61f2eb437c90aaa: Scheduling FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5): perf score=2.188937
I20260812 06:17:54.821348 11900 maintenance_manager.cc:643] P d3856062b71a4d95a61f2eb437c90aaa: FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3882,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:54.821976 12007 maintenance_manager.cc:419] P d3856062b71a4d95a61f2eb437c90aaa: Scheduling MajorDeltaCompactionOp(a51c85635a24499987232b018791a2a5): perf score=1.000000
I20260812 06:17:54.939440 11900 maintenance_manager.cc:643] P d3856062b71a4d95a61f2eb437c90aaa: MajorDeltaCompactionOp(a51c85635a24499987232b018791a2a5) complete. Timing: real 0.117s	user 0.091s	sys 0.026s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713273,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":168,"lbm_read_time_us":8271,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21169,"lbm_writes_lt_1ms":443,"mutex_wait_us":27,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":28800,"update_count":2000}
I20260812 06:17:54.939940 12007 maintenance_manager.cc:419] P d3856062b71a4d95a61f2eb437c90aaa: Scheduling FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5): perf score=10.126437
I20260812 06:17:54.987797 11900 maintenance_manager.cc:643] P d3856062b71a4d95a61f2eb437c90aaa: FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5) complete. Timing: real 0.048s	user 0.024s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13238,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:54.988369 12007 maintenance_manager.cc:419] P d3856062b71a4d95a61f2eb437c90aaa: Scheduling FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5): perf score=2.188937
I20260812 06:17:55.003690 11900 maintenance_manager.cc:643] P d3856062b71a4d95a61f2eb437c90aaa: FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5) complete. Timing: real 0.015s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5780,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:55.004184 12007 maintenance_manager.cc:419] P d3856062b71a4d95a61f2eb437c90aaa: Scheduling MajorDeltaCompactionOp(a51c85635a24499987232b018791a2a5): perf score=1.000000
I20260812 06:17:55.149993 11900 maintenance_manager.cc:643] P d3856062b71a4d95a61f2eb437c90aaa: MajorDeltaCompactionOp(a51c85635a24499987232b018791a2a5) complete. Timing: real 0.146s	user 0.091s	sys 0.055s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":500,"lbm_read_time_us":10512,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23148,"lbm_writes_lt_1ms":443,"mutex_wait_us":268,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2000}
I20260812 06:17:55.150563 12007 maintenance_manager.cc:419] P d3856062b71a4d95a61f2eb437c90aaa: Scheduling FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5): perf score=10.126437
I20260812 06:17:55.195323 11900 maintenance_manager.cc:643] P d3856062b71a4d95a61f2eb437c90aaa: FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5) complete. Timing: real 0.045s	user 0.014s	sys 0.026s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17831,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:55.195756 12007 maintenance_manager.cc:419] P d3856062b71a4d95a61f2eb437c90aaa: Scheduling FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5): perf score=2.188937
I20260812 06:17:55.206187 11900 maintenance_manager.cc:643] P d3856062b71a4d95a61f2eb437c90aaa: FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5) complete. Timing: real 0.010s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3832,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:55.206846 12007 maintenance_manager.cc:419] P d3856062b71a4d95a61f2eb437c90aaa: Scheduling MajorDeltaCompactionOp(a51c85635a24499987232b018791a2a5): perf score=1.000000
I20260812 06:17:55.325206 11900 maintenance_manager.cc:643] P d3856062b71a4d95a61f2eb437c90aaa: MajorDeltaCompactionOp(a51c85635a24499987232b018791a2a5) complete. Timing: real 0.118s	user 0.096s	sys 0.019s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":207,"lbm_read_time_us":8008,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23140,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2048,"update_count":2000}
I20260812 06:17:55.325834 12007 maintenance_manager.cc:419] P d3856062b71a4d95a61f2eb437c90aaa: Scheduling FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5): perf score=10.126437
I20260812 06:17:55.370219 11900 maintenance_manager.cc:643] P d3856062b71a4d95a61f2eb437c90aaa: FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5) complete. Timing: real 0.044s	user 0.023s	sys 0.012s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":21698,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:17:55.370771 12007 maintenance_manager.cc:419] P d3856062b71a4d95a61f2eb437c90aaa: Scheduling FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5): perf score=2.188937
I20260812 06:17:55.380853 11900 maintenance_manager.cc:643] P d3856062b71a4d95a61f2eb437c90aaa: FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3722,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:55.381553 12007 maintenance_manager.cc:419] P d3856062b71a4d95a61f2eb437c90aaa: Scheduling FlushMRSOp(a51c85635a24499987232b018791a2a5): perf score=1.000000
I20260812 06:17:55.413712 11900 maintenance_manager.cc:643] P d3856062b71a4d95a61f2eb437c90aaa: FlushMRSOp(a51c85635a24499987232b018791a2a5) complete. Timing: real 0.032s	user 0.031s	sys 0.001s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":68,"dirs.run_cpu_time_us":210,"dirs.run_wall_time_us":1193,"drs_written":1,"lbm_read_time_us":57,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1805,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:17:55.414399 12007 maintenance_manager.cc:419] P d3856062b71a4d95a61f2eb437c90aaa: Scheduling LogGCOp(a51c85635a24499987232b018791a2a5): free 124710298 bytes of WAL
I20260812 06:17:55.414647 11900 log_reader.cc:385] T a51c85635a24499987232b018791a2a5: removed 12 log segments from log reader
I20260812 06:17:55.414705 11900 log.cc:1079] T a51c85635a24499987232b018791a2a5 P d3856062b71a4d95a61f2eb437c90aaa: Deleting log segment in path: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515468429503-11384-0/minicluster-data/ts-0-root/wals/a51c85635a24499987232b018791a2a5/wal-000000003 (ops 12-16)
I20260812 06:17:55.414793 11900 log.cc:1079] T a51c85635a24499987232b018791a2a5 P d3856062b71a4d95a61f2eb437c90aaa: Deleting log segment in path: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515468429503-11384-0/minicluster-data/ts-0-root/wals/a51c85635a24499987232b018791a2a5/wal-000000004 (ops 17-21)
I20260812 06:17:55.414848 11900 log.cc:1079] T a51c85635a24499987232b018791a2a5 P d3856062b71a4d95a61f2eb437c90aaa: Deleting log segment in path: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515468429503-11384-0/minicluster-data/ts-0-root/wals/a51c85635a24499987232b018791a2a5/wal-000000005 (ops 22-26)
I20260812 06:17:55.414893 11900 log.cc:1079] T a51c85635a24499987232b018791a2a5 P d3856062b71a4d95a61f2eb437c90aaa: Deleting log segment in path: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515468429503-11384-0/minicluster-data/ts-0-root/wals/a51c85635a24499987232b018791a2a5/wal-000000006 (ops 27-31)
I20260812 06:17:55.414932 11900 log.cc:1079] T a51c85635a24499987232b018791a2a5 P d3856062b71a4d95a61f2eb437c90aaa: Deleting log segment in path: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515468429503-11384-0/minicluster-data/ts-0-root/wals/a51c85635a24499987232b018791a2a5/wal-000000007 (ops 32-36)
I20260812 06:17:55.414966 11900 log.cc:1079] T a51c85635a24499987232b018791a2a5 P d3856062b71a4d95a61f2eb437c90aaa: Deleting log segment in path: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515468429503-11384-0/minicluster-data/ts-0-root/wals/a51c85635a24499987232b018791a2a5/wal-000000008 (ops 37-41)
I20260812 06:17:55.415020 11900 log.cc:1079] T a51c85635a24499987232b018791a2a5 P d3856062b71a4d95a61f2eb437c90aaa: Deleting log segment in path: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515468429503-11384-0/minicluster-data/ts-0-root/wals/a51c85635a24499987232b018791a2a5/wal-000000009 (ops 42-46)
I20260812 06:17:55.415062 11900 log.cc:1079] T a51c85635a24499987232b018791a2a5 P d3856062b71a4d95a61f2eb437c90aaa: Deleting log segment in path: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515468429503-11384-0/minicluster-data/ts-0-root/wals/a51c85635a24499987232b018791a2a5/wal-000000010 (ops 47-51)
I20260812 06:17:55.415097 11900 log.cc:1079] T a51c85635a24499987232b018791a2a5 P d3856062b71a4d95a61f2eb437c90aaa: Deleting log segment in path: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515468429503-11384-0/minicluster-data/ts-0-root/wals/a51c85635a24499987232b018791a2a5/wal-000000011 (ops 52-56)
I20260812 06:17:55.415132 11900 log.cc:1079] T a51c85635a24499987232b018791a2a5 P d3856062b71a4d95a61f2eb437c90aaa: Deleting log segment in path: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515468429503-11384-0/minicluster-data/ts-0-root/wals/a51c85635a24499987232b018791a2a5/wal-000000012 (ops 57-61)
I20260812 06:17:55.415172 11900 log.cc:1079] T a51c85635a24499987232b018791a2a5 P d3856062b71a4d95a61f2eb437c90aaa: Deleting log segment in path: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515468429503-11384-0/minicluster-data/ts-0-root/wals/a51c85635a24499987232b018791a2a5/wal-000000013 (ops 62-66)
I20260812 06:17:55.415217 11900 log.cc:1079] T a51c85635a24499987232b018791a2a5 P d3856062b71a4d95a61f2eb437c90aaa: Deleting log segment in path: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515468429503-11384-0/minicluster-data/ts-0-root/wals/a51c85635a24499987232b018791a2a5/wal-000000014 (ops 67-71)
I20260812 06:17:55.444356 11900 maintenance_manager.cc:643] P d3856062b71a4d95a61f2eb437c90aaa: LogGCOp(a51c85635a24499987232b018791a2a5) complete. Timing: real 0.030s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:17:55.444787 12007 maintenance_manager.cc:419] P d3856062b71a4d95a61f2eb437c90aaa: Scheduling UndoDeltaBlockGCOp(a51c85635a24499987232b018791a2a5): 462 bytes on disk
I20260812 06:17:55.445307 11900 maintenance_manager.cc:643] P d3856062b71a4d95a61f2eb437c90aaa: UndoDeltaBlockGCOp(a51c85635a24499987232b018791a2a5) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":72,"lbm_reads_lt_1ms":4}
I20260812 06:17:55.445955 12007 maintenance_manager.cc:419] P d3856062b71a4d95a61f2eb437c90aaa: Scheduling FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5): perf score=3.181125
I20260812 06:17:55.462001 11900 maintenance_manager.cc:643] P d3856062b71a4d95a61f2eb437c90aaa: FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5) complete. Timing: real 0.016s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":6142,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:55.462412 12007 maintenance_manager.cc:419] P d3856062b71a4d95a61f2eb437c90aaa: Scheduling FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5): perf score=2.188937
I20260812 06:17:55.472466 11900 maintenance_manager.cc:643] P d3856062b71a4d95a61f2eb437c90aaa: FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3466,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:55.472854 12007 maintenance_manager.cc:419] P d3856062b71a4d95a61f2eb437c90aaa: Scheduling MajorDeltaCompactionOp(a51c85635a24499987232b018791a2a5): perf score=1.000000
I20260812 06:17:55.634788 11900 maintenance_manager.cc:643] P d3856062b71a4d95a61f2eb437c90aaa: MajorDeltaCompactionOp(a51c85635a24499987232b018791a2a5) complete. Timing: real 0.162s	user 0.127s	sys 0.034s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28918323,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":697,"lbm_read_time_us":11187,"lbm_reads_lt_1ms":674,"lbm_write_time_us":30521,"lbm_writes_lt_1ms":643,"mutex_wait_us":34,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":6528,"thread_start_us":72,"threads_started":1,"update_count":3000}
I20260812 06:17:55.635293 12007 maintenance_manager.cc:419] P d3856062b71a4d95a61f2eb437c90aaa: Scheduling FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5): perf score=14.095187
I20260812 06:17:55.689633 11900 maintenance_manager.cc:643] P d3856062b71a4d95a61f2eb437c90aaa: FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5) complete. Timing: real 0.054s	user 0.028s	sys 0.021s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21797,"lbm_writes_lt_1ms":403,"mutex_wait_us":3,"reinsert_count":0,"update_count":2000}
I20260812 06:17:55.690114 12007 maintenance_manager.cc:419] P d3856062b71a4d95a61f2eb437c90aaa: Scheduling FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5): perf score=2.188937
I20260812 06:17:55.700441 11900 maintenance_manager.cc:643] P d3856062b71a4d95a61f2eb437c90aaa: FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3720,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:55.700994 12007 maintenance_manager.cc:419] P d3856062b71a4d95a61f2eb437c90aaa: Scheduling MajorDeltaCompactionOp(a51c85635a24499987232b018791a2a5): perf score=1.000000
I20260812 06:17:55.851137 11900 maintenance_manager.cc:643] P d3856062b71a4d95a61f2eb437c90aaa: MajorDeltaCompactionOp(a51c85635a24499987232b018791a2a5) complete. Timing: real 0.150s	user 0.124s	sys 0.026s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1235,"lbm_read_time_us":9834,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28093,"lbm_writes_lt_1ms":543,"mutex_wait_us":404,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14720,"update_count":2500}
I20260812 06:17:55.851902 12007 maintenance_manager.cc:419] P d3856062b71a4d95a61f2eb437c90aaa: Scheduling FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5): perf score=10.126437
I20260812 06:17:55.888533 11900 maintenance_manager.cc:643] P d3856062b71a4d95a61f2eb437c90aaa: FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5) complete. Timing: real 0.036s	user 0.016s	sys 0.018s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":16121,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:55.889328 12007 maintenance_manager.cc:419] P d3856062b71a4d95a61f2eb437c90aaa: Scheduling FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5): perf score=2.188937
I20260812 06:17:55.908790 11900 maintenance_manager.cc:643] P d3856062b71a4d95a61f2eb437c90aaa: FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5) complete. Timing: real 0.019s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5654,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:55.909350 12007 maintenance_manager.cc:419] P d3856062b71a4d95a61f2eb437c90aaa: Scheduling MajorDeltaCompactionOp(a51c85635a24499987232b018791a2a5): perf score=1.000000
I20260812 06:17:56.051833 11900 maintenance_manager.cc:643] P d3856062b71a4d95a61f2eb437c90aaa: MajorDeltaCompactionOp(a51c85635a24499987232b018791a2a5) complete. Timing: real 0.142s	user 0.105s	sys 0.035s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713271,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":630,"lbm_read_time_us":10086,"lbm_reads_lt_1ms":464,"lbm_write_time_us":22445,"lbm_writes_lt_1ms":443,"mutex_wait_us":53,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":13568,"update_count":2000}
I20260812 06:17:56.052459 12007 maintenance_manager.cc:419] P d3856062b71a4d95a61f2eb437c90aaa: Scheduling FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5): perf score=11.118625
I20260812 06:17:56.098958 11900 maintenance_manager.cc:643] P d3856062b71a4d95a61f2eb437c90aaa: FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5) complete. Timing: real 0.046s	user 0.036s	sys 0.007s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":19867,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:17:56.099486 12007 maintenance_manager.cc:419] P d3856062b71a4d95a61f2eb437c90aaa: Scheduling FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5): perf score=2.188937
I20260812 06:17:56.127633 11900 maintenance_manager.cc:643] P d3856062b71a4d95a61f2eb437c90aaa: FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5) complete. Timing: real 0.028s	user 0.018s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7230,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:56.128135 12007 maintenance_manager.cc:419] P d3856062b71a4d95a61f2eb437c90aaa: Scheduling FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5): perf score=2.188937
I20260812 06:17:56.138599 11900 maintenance_manager.cc:643] P d3856062b71a4d95a61f2eb437c90aaa: FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3831,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:56.139096 12007 maintenance_manager.cc:419] P d3856062b71a4d95a61f2eb437c90aaa: Scheduling MajorDeltaCompactionOp(a51c85635a24499987232b018791a2a5): perf score=1.000000
I20260812 06:17:56.326330 11900 maintenance_manager.cc:643] P d3856062b71a4d95a61f2eb437c90aaa: MajorDeltaCompactionOp(a51c85635a24499987232b018791a2a5) complete. Timing: real 0.187s	user 0.108s	sys 0.068s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815793,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":380,"lbm_read_time_us":12713,"lbm_reads_lt_1ms":573,"lbm_write_time_us":27609,"lbm_writes_lt_1ms":543,"mutex_wait_us":3,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4224,"update_count":2500}
I20260812 06:17:56.326875 12007 maintenance_manager.cc:419] P d3856062b71a4d95a61f2eb437c90aaa: Scheduling FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5): perf score=14.095187
I20260812 06:17:56.377950 11900 maintenance_manager.cc:643] P d3856062b71a4d95a61f2eb437c90aaa: FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5) complete. Timing: real 0.051s	user 0.031s	sys 0.019s Metrics: {"bytes_written":16409898,"delete_count":0,"lbm_write_time_us":22586,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:17:56.378486 12007 maintenance_manager.cc:419] P d3856062b71a4d95a61f2eb437c90aaa: Scheduling FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5): perf score=2.188937
I20260812 06:17:56.401872 11900 maintenance_manager.cc:643] P d3856062b71a4d95a61f2eb437c90aaa: FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5) complete. Timing: real 0.023s	user 0.011s	sys 0.012s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6029,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:56.402381 12007 maintenance_manager.cc:419] P d3856062b71a4d95a61f2eb437c90aaa: Scheduling MajorDeltaCompactionOp(a51c85635a24499987232b018791a2a5): perf score=1.000000
I20260812 06:17:56.571815 11900 maintenance_manager.cc:643] P d3856062b71a4d95a61f2eb437c90aaa: MajorDeltaCompactionOp(a51c85635a24499987232b018791a2a5) complete. Timing: real 0.169s	user 0.111s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815679,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":983,"lbm_read_time_us":11102,"lbm_reads_lt_1ms":564,"lbm_write_time_us":26882,"lbm_writes_lt_1ms":543,"mutex_wait_us":298,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4096,"update_count":2500}
I20260812 06:17:56.572301 12007 maintenance_manager.cc:419] P d3856062b71a4d95a61f2eb437c90aaa: Scheduling FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5): perf score=14.095187
I20260812 06:17:56.613689 11900 maintenance_manager.cc:643] P d3856062b71a4d95a61f2eb437c90aaa: FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5) complete. Timing: real 0.041s	user 0.019s	sys 0.019s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":17040,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:56.614266 12007 maintenance_manager.cc:419] P d3856062b71a4d95a61f2eb437c90aaa: Scheduling FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5): perf score=2.188937
I20260812 06:17:56.629622 11900 maintenance_manager.cc:643] P d3856062b71a4d95a61f2eb437c90aaa: FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5) complete. Timing: real 0.015s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5587,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:56.630137 12007 maintenance_manager.cc:419] P d3856062b71a4d95a61f2eb437c90aaa: Scheduling MajorDeltaCompactionOp(a51c85635a24499987232b018791a2a5): perf score=1.000000
I20260812 06:17:56.775290 11900 maintenance_manager.cc:643] P d3856062b71a4d95a61f2eb437c90aaa: MajorDeltaCompactionOp(a51c85635a24499987232b018791a2a5) complete. Timing: real 0.145s	user 0.090s	sys 0.053s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":172,"lbm_read_time_us":9976,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27493,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4224,"update_count":2500}
I20260812 06:17:56.775870 12007 maintenance_manager.cc:419] P d3856062b71a4d95a61f2eb437c90aaa: Scheduling FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5): perf score=11.118625
I20260812 06:17:56.814549 11900 maintenance_manager.cc:643] P d3856062b71a4d95a61f2eb437c90aaa: FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5) complete. Timing: real 0.038s	user 0.025s	sys 0.013s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":16760,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:56.815439 12007 maintenance_manager.cc:419] P d3856062b71a4d95a61f2eb437c90aaa: Scheduling FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5): perf score=2.188937
I20260812 06:17:56.826468 11900 maintenance_manager.cc:643] P d3856062b71a4d95a61f2eb437c90aaa: FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5) complete. Timing: real 0.011s	user 0.009s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4016,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:56.827033 12007 maintenance_manager.cc:419] P d3856062b71a4d95a61f2eb437c90aaa: Scheduling FlushMRSOp(a51c85635a24499987232b018791a2a5): perf score=1.000000
I20260812 06:17:56.854243 11900 maintenance_manager.cc:643] P d3856062b71a4d95a61f2eb437c90aaa: FlushMRSOp(a51c85635a24499987232b018791a2a5) complete. Timing: real 0.027s	user 0.020s	sys 0.007s Metrics: {"bytes_written":1234479,"cfile_init":1,"dirs.queue_time_us":57,"dirs.run_cpu_time_us":245,"dirs.run_wall_time_us":1483,"drs_written":1,"lbm_read_time_us":36,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1530,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:17:56.855024 12007 maintenance_manager.cc:419] P d3856062b71a4d95a61f2eb437c90aaa: Scheduling LogGCOp(a51c85635a24499987232b018791a2a5): free 124710310 bytes of WAL
I20260812 06:17:56.855263 11900 log_reader.cc:385] T a51c85635a24499987232b018791a2a5: removed 12 log segments from log reader
I20260812 06:17:56.855312 11900 log.cc:1079] T a51c85635a24499987232b018791a2a5 P d3856062b71a4d95a61f2eb437c90aaa: Deleting log segment in path: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515468429503-11384-0/minicluster-data/ts-0-root/wals/a51c85635a24499987232b018791a2a5/wal-000000015 (ops 72-76)
I20260812 06:17:56.855350 11900 log.cc:1079] T a51c85635a24499987232b018791a2a5 P d3856062b71a4d95a61f2eb437c90aaa: Deleting log segment in path: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515468429503-11384-0/minicluster-data/ts-0-root/wals/a51c85635a24499987232b018791a2a5/wal-000000016 (ops 77-81)
I20260812 06:17:56.855382 11900 log.cc:1079] T a51c85635a24499987232b018791a2a5 P d3856062b71a4d95a61f2eb437c90aaa: Deleting log segment in path: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515468429503-11384-0/minicluster-data/ts-0-root/wals/a51c85635a24499987232b018791a2a5/wal-000000017 (ops 82-86)
I20260812 06:17:56.855414 11900 log.cc:1079] T a51c85635a24499987232b018791a2a5 P d3856062b71a4d95a61f2eb437c90aaa: Deleting log segment in path: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515468429503-11384-0/minicluster-data/ts-0-root/wals/a51c85635a24499987232b018791a2a5/wal-000000018 (ops 87-91)
I20260812 06:17:56.855444 11900 log.cc:1079] T a51c85635a24499987232b018791a2a5 P d3856062b71a4d95a61f2eb437c90aaa: Deleting log segment in path: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515468429503-11384-0/minicluster-data/ts-0-root/wals/a51c85635a24499987232b018791a2a5/wal-000000019 (ops 92-96)
I20260812 06:17:56.855474 11900 log.cc:1079] T a51c85635a24499987232b018791a2a5 P d3856062b71a4d95a61f2eb437c90aaa: Deleting log segment in path: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515468429503-11384-0/minicluster-data/ts-0-root/wals/a51c85635a24499987232b018791a2a5/wal-000000020 (ops 97-101)
I20260812 06:17:56.855507 11900 log.cc:1079] T a51c85635a24499987232b018791a2a5 P d3856062b71a4d95a61f2eb437c90aaa: Deleting log segment in path: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515468429503-11384-0/minicluster-data/ts-0-root/wals/a51c85635a24499987232b018791a2a5/wal-000000021 (ops 102-106)
I20260812 06:17:56.855536 11900 log.cc:1079] T a51c85635a24499987232b018791a2a5 P d3856062b71a4d95a61f2eb437c90aaa: Deleting log segment in path: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515468429503-11384-0/minicluster-data/ts-0-root/wals/a51c85635a24499987232b018791a2a5/wal-000000022 (ops 107-111)
I20260812 06:17:56.855566 11900 log.cc:1079] T a51c85635a24499987232b018791a2a5 P d3856062b71a4d95a61f2eb437c90aaa: Deleting log segment in path: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515468429503-11384-0/minicluster-data/ts-0-root/wals/a51c85635a24499987232b018791a2a5/wal-000000023 (ops 112-116)
I20260812 06:17:56.855595 11900 log.cc:1079] T a51c85635a24499987232b018791a2a5 P d3856062b71a4d95a61f2eb437c90aaa: Deleting log segment in path: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515468429503-11384-0/minicluster-data/ts-0-root/wals/a51c85635a24499987232b018791a2a5/wal-000000024 (ops 117-121)
I20260812 06:17:56.855624 11900 log.cc:1079] T a51c85635a24499987232b018791a2a5 P d3856062b71a4d95a61f2eb437c90aaa: Deleting log segment in path: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515468429503-11384-0/minicluster-data/ts-0-root/wals/a51c85635a24499987232b018791a2a5/wal-000000025 (ops 122-126)
I20260812 06:17:56.855654 11900 log.cc:1079] T a51c85635a24499987232b018791a2a5 P d3856062b71a4d95a61f2eb437c90aaa: Deleting log segment in path: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515468429503-11384-0/minicluster-data/ts-0-root/wals/a51c85635a24499987232b018791a2a5/wal-000000026 (ops 127-131)
I20260812 06:17:56.879317 11900 maintenance_manager.cc:643] P d3856062b71a4d95a61f2eb437c90aaa: LogGCOp(a51c85635a24499987232b018791a2a5) complete. Timing: real 0.024s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:17:56.879739 12007 maintenance_manager.cc:419] P d3856062b71a4d95a61f2eb437c90aaa: Scheduling UndoDeltaBlockGCOp(a51c85635a24499987232b018791a2a5): 473 bytes on disk
I20260812 06:17:56.880225 11900 maintenance_manager.cc:643] P d3856062b71a4d95a61f2eb437c90aaa: UndoDeltaBlockGCOp(a51c85635a24499987232b018791a2a5) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":71,"lbm_reads_lt_1ms":4}
I20260812 06:17:56.880831 12007 maintenance_manager.cc:419] P d3856062b71a4d95a61f2eb437c90aaa: Scheduling FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5): perf score=3.181125
I20260812 06:17:56.898370 11900 maintenance_manager.cc:643] P d3856062b71a4d95a61f2eb437c90aaa: FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5) complete. Timing: real 0.017s	user 0.012s	sys 0.005s Metrics: {"bytes_written":4512902,"delete_count":0,"lbm_write_time_us":6943,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:56.898797 12007 maintenance_manager.cc:419] P d3856062b71a4d95a61f2eb437c90aaa: Scheduling FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5): perf score=2.188937
I20260812 06:17:56.908515 11900 maintenance_manager.cc:643] P d3856062b71a4d95a61f2eb437c90aaa: FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5) complete. Timing: real 0.010s	user 0.004s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3572,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:56.908912 12007 maintenance_manager.cc:419] P d3856062b71a4d95a61f2eb437c90aaa: Scheduling MajorDeltaCompactionOp(a51c85635a24499987232b018791a2a5): perf score=1.000000
I20260812 06:17:57.104437 11900 maintenance_manager.cc:643] P d3856062b71a4d95a61f2eb437c90aaa: MajorDeltaCompactionOp(a51c85635a24499987232b018791a2a5) complete. Timing: real 0.195s	user 0.112s	sys 0.076s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28918316,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":406,"lbm_read_time_us":11530,"lbm_reads_lt_1ms":674,"lbm_write_time_us":30738,"lbm_writes_lt_1ms":643,"mutex_wait_us":61,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":7936,"thread_start_us":101,"threads_started":1,"update_count":3000}
I20260812 06:17:57.105052 12007 maintenance_manager.cc:419] P d3856062b71a4d95a61f2eb437c90aaa: Scheduling FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5): perf score=14.095187
I20260812 06:17:57.159791 11900 maintenance_manager.cc:643] P d3856062b71a4d95a61f2eb437c90aaa: FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5) complete. Timing: real 0.055s	user 0.020s	sys 0.031s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23276,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:17:57.160347 12007 maintenance_manager.cc:419] P d3856062b71a4d95a61f2eb437c90aaa: Scheduling FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5): perf score=2.188937
I20260812 06:17:57.186088 11900 maintenance_manager.cc:643] P d3856062b71a4d95a61f2eb437c90aaa: FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5) complete. Timing: real 0.026s	user 0.012s	sys 0.012s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5891,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:57.186726 12007 maintenance_manager.cc:419] P d3856062b71a4d95a61f2eb437c90aaa: Scheduling FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5): perf score=1.000000
I20260812 06:17:57.196031 11900 maintenance_manager.cc:643] P d3856062b71a4d95a61f2eb437c90aaa: FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5) complete. Timing: real 0.009s	user 0.005s	sys 0.000s Metrics: {"bytes_written":1312956,"delete_count":0,"lbm_write_time_us":2012,"lbm_writes_lt_1ms":35,"reinsert_count":0,"update_count":160}
I20260812 06:17:57.196413 12007 maintenance_manager.cc:419] P d3856062b71a4d95a61f2eb437c90aaa: Scheduling FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5): perf score=1.196750
I20260812 06:17:57.204047 11900 maintenance_manager.cc:643] P d3856062b71a4d95a61f2eb437c90aaa: FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5) complete. Timing: real 0.007s	user 0.003s	sys 0.003s Metrics: {"bytes_written":2789855,"delete_count":0,"lbm_write_time_us":2749,"lbm_writes_lt_1ms":71,"reinsert_count":0,"update_count":340}
I20260812 06:17:57.204449 12007 maintenance_manager.cc:419] P d3856062b71a4d95a61f2eb437c90aaa: Scheduling MajorDeltaCompactionOp(a51c85635a24499987232b018791a2a5): perf score=1.000000
I20260812 06:17:57.392216 11900 maintenance_manager.cc:643] P d3856062b71a4d95a61f2eb437c90aaa: MajorDeltaCompactionOp(a51c85635a24499987232b018791a2a5) complete. Timing: real 0.188s	user 0.146s	sys 0.039s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28918238,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":148,"lbm_read_time_us":12225,"lbm_reads_lt_1ms":674,"lbm_write_time_us":32135,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":3000}
I20260812 06:17:57.392913 12007 maintenance_manager.cc:419] P d3856062b71a4d95a61f2eb437c90aaa: Scheduling FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5): perf score=14.095187
I20260812 06:17:57.451162 11900 maintenance_manager.cc:643] P d3856062b71a4d95a61f2eb437c90aaa: FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5) complete. Timing: real 0.058s	user 0.038s	sys 0.019s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19132,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:57.451725 12007 maintenance_manager.cc:419] P d3856062b71a4d95a61f2eb437c90aaa: Scheduling FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5): perf score=2.188937
I20260812 06:17:57.462368 11900 maintenance_manager.cc:643] P d3856062b71a4d95a61f2eb437c90aaa: FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5) complete. Timing: real 0.010s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3800,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:57.463989 12007 maintenance_manager.cc:419] P d3856062b71a4d95a61f2eb437c90aaa: Scheduling MajorDeltaCompactionOp(a51c85635a24499987232b018791a2a5): perf score=1.000000
I20260812 06:17:57.642342 11900 maintenance_manager.cc:643] P d3856062b71a4d95a61f2eb437c90aaa: MajorDeltaCompactionOp(a51c85635a24499987232b018791a2a5) complete. Timing: real 0.178s	user 0.123s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":120,"lbm_read_time_us":12219,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28378,"lbm_writes_lt_1ms":543,"mutex_wait_us":24,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11392,"update_count":2500}
I20260812 06:17:57.642884 12007 maintenance_manager.cc:419] P d3856062b71a4d95a61f2eb437c90aaa: Scheduling FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5): perf score=14.095187
I20260812 06:17:57.697899 11900 maintenance_manager.cc:643] P d3856062b71a4d95a61f2eb437c90aaa: FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5) complete. Timing: real 0.055s	user 0.023s	sys 0.027s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":17838,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:57.698437 12007 maintenance_manager.cc:419] P d3856062b71a4d95a61f2eb437c90aaa: Scheduling FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5): perf score=2.188937
I20260812 06:17:57.708611 11900 maintenance_manager.cc:643] P d3856062b71a4d95a61f2eb437c90aaa: FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5) complete. Timing: real 0.010s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3868,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:57.709033 12007 maintenance_manager.cc:419] P d3856062b71a4d95a61f2eb437c90aaa: Scheduling MajorDeltaCompactionOp(a51c85635a24499987232b018791a2a5): perf score=1.000000
I20260812 06:17:57.888051 11900 maintenance_manager.cc:643] P d3856062b71a4d95a61f2eb437c90aaa: MajorDeltaCompactionOp(a51c85635a24499987232b018791a2a5) complete. Timing: real 0.179s	user 0.109s	sys 0.065s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":563,"lbm_read_time_us":11341,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29873,"lbm_writes_lt_1ms":543,"mutex_wait_us":240,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4992,"update_count":2500}
I20260812 06:17:57.888811 12007 maintenance_manager.cc:419] P d3856062b71a4d95a61f2eb437c90aaa: Scheduling FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5): perf score=11.118625
I20260812 06:17:57.936312 11900 maintenance_manager.cc:643] P d3856062b71a4d95a61f2eb437c90aaa: FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5) complete. Timing: real 0.047s	user 0.014s	sys 0.027s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":17738,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:17:57.936843 12007 maintenance_manager.cc:419] P d3856062b71a4d95a61f2eb437c90aaa: Scheduling FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5): perf score=2.188937
I20260812 06:17:57.948426 11900 maintenance_manager.cc:643] P d3856062b71a4d95a61f2eb437c90aaa: FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5) complete. Timing: real 0.011s	user 0.004s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3465,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:57.948892 12007 maintenance_manager.cc:419] P d3856062b71a4d95a61f2eb437c90aaa: Scheduling FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5): perf score=2.188937
I20260812 06:17:57.967538 11900 maintenance_manager.cc:643] P d3856062b71a4d95a61f2eb437c90aaa: FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5) complete. Timing: real 0.018s	user 0.010s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3260,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:57.968111 12007 maintenance_manager.cc:419] P d3856062b71a4d95a61f2eb437c90aaa: Scheduling MajorDeltaCompactionOp(a51c85635a24499987232b018791a2a5): perf score=1.000000
I20260812 06:17:58.139416 11900 maintenance_manager.cc:643] P d3856062b71a4d95a61f2eb437c90aaa: MajorDeltaCompactionOp(a51c85635a24499987232b018791a2a5) complete. Timing: real 0.171s	user 0.121s	sys 0.047s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815796,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":552,"lbm_read_time_us":10699,"lbm_reads_lt_1ms":573,"lbm_write_time_us":27951,"lbm_writes_lt_1ms":543,"mutex_wait_us":52,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:17:58.140058 12007 maintenance_manager.cc:419] P d3856062b71a4d95a61f2eb437c90aaa: Scheduling FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5): perf score=11.118625
I20260812 06:17:58.169895 11900 maintenance_manager.cc:643] P d3856062b71a4d95a61f2eb437c90aaa: FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5) complete. Timing: real 0.028s	user 0.020s	sys 0.008s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":11642,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:58.170689 12007 maintenance_manager.cc:419] P d3856062b71a4d95a61f2eb437c90aaa: Scheduling FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5): perf score=2.188937
I20260812 06:17:58.196332 11900 maintenance_manager.cc:643] P d3856062b71a4d95a61f2eb437c90aaa: FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5) complete. Timing: real 0.024s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4001,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:58.196904 12007 maintenance_manager.cc:419] P d3856062b71a4d95a61f2eb437c90aaa: Scheduling FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5): perf score=2.188937
I20260812 06:17:58.206809 11900 maintenance_manager.cc:643] P d3856062b71a4d95a61f2eb437c90aaa: FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3533,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:58.207441 12007 maintenance_manager.cc:419] P d3856062b71a4d95a61f2eb437c90aaa: Scheduling FlushMRSOp(a51c85635a24499987232b018791a2a5): perf score=1.000000
I20260812 06:17:58.238402 11900 maintenance_manager.cc:643] P d3856062b71a4d95a61f2eb437c90aaa: FlushMRSOp(a51c85635a24499987232b018791a2a5) complete. Timing: real 0.031s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1152510,"cfile_init":1,"dirs.queue_time_us":56,"dirs.run_cpu_time_us":131,"dirs.run_wall_time_us":1158,"drs_written":1,"lbm_read_time_us":59,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2074,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28,"spinlock_wait_cycles":9984}
I20260812 06:17:58.239409 12007 maintenance_manager.cc:419] P d3856062b71a4d95a61f2eb437c90aaa: Scheduling FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5): perf score=2.188937
I20260812 06:17:58.253545 11900 maintenance_manager.cc:643] P d3856062b71a4d95a61f2eb437c90aaa: FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5) complete. Timing: real 0.014s	user 0.005s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5627,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:58.254030 12007 maintenance_manager.cc:419] P d3856062b71a4d95a61f2eb437c90aaa: Scheduling LogGCOp(a51c85635a24499987232b018791a2a5): free 120100589 bytes of WAL
I20260812 06:17:58.254263 11900 log_reader.cc:385] T a51c85635a24499987232b018791a2a5: removed 12 log segments from log reader
I20260812 06:17:58.254317 11900 log.cc:1079] T a51c85635a24499987232b018791a2a5 P d3856062b71a4d95a61f2eb437c90aaa: Deleting log segment in path: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515468429503-11384-0/minicluster-data/ts-0-root/wals/a51c85635a24499987232b018791a2a5/wal-000000027 (ops 132-136)
I20260812 06:17:58.254354 11900 log.cc:1079] T a51c85635a24499987232b018791a2a5 P d3856062b71a4d95a61f2eb437c90aaa: Deleting log segment in path: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515468429503-11384-0/minicluster-data/ts-0-root/wals/a51c85635a24499987232b018791a2a5/wal-000000028 (ops 137-141)
I20260812 06:17:58.254390 11900 log.cc:1079] T a51c85635a24499987232b018791a2a5 P d3856062b71a4d95a61f2eb437c90aaa: Deleting log segment in path: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515468429503-11384-0/minicluster-data/ts-0-root/wals/a51c85635a24499987232b018791a2a5/wal-000000029 (ops 142-146)
I20260812 06:17:58.254431 11900 log.cc:1079] T a51c85635a24499987232b018791a2a5 P d3856062b71a4d95a61f2eb437c90aaa: Deleting log segment in path: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515468429503-11384-0/minicluster-data/ts-0-root/wals/a51c85635a24499987232b018791a2a5/wal-000000030 (ops 147-151)
I20260812 06:17:58.254468 11900 log.cc:1079] T a51c85635a24499987232b018791a2a5 P d3856062b71a4d95a61f2eb437c90aaa: Deleting log segment in path: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515468429503-11384-0/minicluster-data/ts-0-root/wals/a51c85635a24499987232b018791a2a5/wal-000000031 (ops 152-156)
I20260812 06:17:58.254505 11900 log.cc:1079] T a51c85635a24499987232b018791a2a5 P d3856062b71a4d95a61f2eb437c90aaa: Deleting log segment in path: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515468429503-11384-0/minicluster-data/ts-0-root/wals/a51c85635a24499987232b018791a2a5/wal-000000032 (ops 157-160)
I20260812 06:17:58.254542 11900 log.cc:1079] T a51c85635a24499987232b018791a2a5 P d3856062b71a4d95a61f2eb437c90aaa: Deleting log segment in path: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515468429503-11384-0/minicluster-data/ts-0-root/wals/a51c85635a24499987232b018791a2a5/wal-000000033 (ops 161-165)
I20260812 06:17:58.254580 11900 log.cc:1079] T a51c85635a24499987232b018791a2a5 P d3856062b71a4d95a61f2eb437c90aaa: Deleting log segment in path: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515468429503-11384-0/minicluster-data/ts-0-root/wals/a51c85635a24499987232b018791a2a5/wal-000000034 (ops 166-170)
I20260812 06:17:58.254626 11900 log.cc:1079] T a51c85635a24499987232b018791a2a5 P d3856062b71a4d95a61f2eb437c90aaa: Deleting log segment in path: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515468429503-11384-0/minicluster-data/ts-0-root/wals/a51c85635a24499987232b018791a2a5/wal-000000035 (ops 171-174)
I20260812 06:17:58.254662 11900 log.cc:1079] T a51c85635a24499987232b018791a2a5 P d3856062b71a4d95a61f2eb437c90aaa: Deleting log segment in path: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515468429503-11384-0/minicluster-data/ts-0-root/wals/a51c85635a24499987232b018791a2a5/wal-000000036 (ops 175-179)
I20260812 06:17:58.254699 11900 log.cc:1079] T a51c85635a24499987232b018791a2a5 P d3856062b71a4d95a61f2eb437c90aaa: Deleting log segment in path: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515468429503-11384-0/minicluster-data/ts-0-root/wals/a51c85635a24499987232b018791a2a5/wal-000000037 (ops 180-184)
I20260812 06:17:58.254736 11900 log.cc:1079] T a51c85635a24499987232b018791a2a5 P d3856062b71a4d95a61f2eb437c90aaa: Deleting log segment in path: /tmp/dist-test-taskcsm6GR/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515468429503-11384-0/minicluster-data/ts-0-root/wals/a51c85635a24499987232b018791a2a5/wal-000000038 (ops 185-188)
I20260812 06:17:58.278389 11900 maintenance_manager.cc:643] P d3856062b71a4d95a61f2eb437c90aaa: LogGCOp(a51c85635a24499987232b018791a2a5) complete. Timing: real 0.024s	user 0.004s	sys 0.019s Metrics: {}
I20260812 06:17:58.278964 12007 maintenance_manager.cc:419] P d3856062b71a4d95a61f2eb437c90aaa: Scheduling MajorDeltaCompactionOp(a51c85635a24499987232b018791a2a5): perf score=1.000000
I20260812 06:17:58.478434 11900 maintenance_manager.cc:643] P d3856062b71a4d95a61f2eb437c90aaa: MajorDeltaCompactionOp(a51c85635a24499987232b018791a2a5) complete. Timing: real 0.199s	user 0.115s	sys 0.084s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28918324,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":123,"lbm_read_time_us":13358,"lbm_reads_lt_1ms":666,"lbm_write_time_us":32084,"lbm_writes_lt_1ms":643,"mutex_wait_us":25,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":82560,"thread_start_us":70,"threads_started":1,"update_count":3000}
I20260812 06:17:58.478988 12007 maintenance_manager.cc:419] P d3856062b71a4d95a61f2eb437c90aaa: Scheduling UndoDeltaBlockGCOp(a51c85635a24499987232b018791a2a5): 447 bytes on disk
I20260812 06:17:58.479411 11900 maintenance_manager.cc:643] P d3856062b71a4d95a61f2eb437c90aaa: UndoDeltaBlockGCOp(a51c85635a24499987232b018791a2a5) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4}
I20260812 06:17:58.480043 12007 maintenance_manager.cc:419] P d3856062b71a4d95a61f2eb437c90aaa: Scheduling FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5): perf score=18.063937
I20260812 06:17:58.543332 11900 maintenance_manager.cc:643] P d3856062b71a4d95a61f2eb437c90aaa: FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5) complete. Timing: real 0.063s	user 0.022s	sys 0.039s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":24692,"lbm_writes_lt_1ms":503,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":2500}
I20260812 06:17:58.544040 12007 maintenance_manager.cc:419] P d3856062b71a4d95a61f2eb437c90aaa: Scheduling FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5): perf score=2.188937
I20260812 06:17:58.555223 11900 maintenance_manager.cc:643] P d3856062b71a4d95a61f2eb437c90aaa: FlushDeltaMemStoresOp(a51c85635a24499987232b018791a2a5) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3825,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:58.555670 12007 maintenance_manager.cc:419] P d3856062b71a4d95a61f2eb437c90aaa: Scheduling MajorDeltaCompactionOp(a51c85635a24499987232b018791a2a5): perf score=1.000000
I20260812 06:17:58.586894 11384 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.722s	user 1.707s	sys 0.170s
I20260812 06:17:58.677110 11384 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.090s	user 0.001s	sys 0.000s
I20260812 06:17:58.677619 11384 tablet_server.cc:179] TabletServer@127.11.30.1:0 shutting down...
I20260812 06:17:58.744020 11900 maintenance_manager.cc:643] P d3856062b71a4d95a61f2eb437c90aaa: MajorDeltaCompactionOp(a51c85635a24499987232b018791a2a5) complete. Timing: real 0.188s	user 0.112s	sys 0.076s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918097,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":965,"lbm_read_time_us":12740,"lbm_reads_lt_1ms":668,"lbm_write_time_us":34347,"lbm_writes_lt_1ms":643,"mutex_wait_us":348,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":4736,"update_count":3000}
I20260812 06:17:58.744606 11384 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:58.744835 11384 tablet_replica.cc:333] T a51c85635a24499987232b018791a2a5 P d3856062b71a4d95a61f2eb437c90aaa: stopping tablet replica
I20260812 06:17:58.745005 11384 raft_consensus.cc:2243] T a51c85635a24499987232b018791a2a5 P d3856062b71a4d95a61f2eb437c90aaa [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:58.745157 11384 raft_consensus.cc:2272] T a51c85635a24499987232b018791a2a5 P d3856062b71a4d95a61f2eb437c90aaa [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:58.750110 11384 tablet_server.cc:196] TabletServer@127.11.30.1:0 shutdown complete.
I20260812 06:17:58.795984 11384 master.cc:562] Master@127.11.30.62:38153 shutting down...
I20260812 06:17:58.799032 11384 raft_consensus.cc:2243] T 00000000000000000000000000000000 P a46f99160da042fc98d42bd0c72926f4 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:58.799232 11384 raft_consensus.cc:2272] T 00000000000000000000000000000000 P a46f99160da042fc98d42bd0c72926f4 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:58.799307 11384 tablet_replica.cc:333] T 00000000000000000000000000000000 P a46f99160da042fc98d42bd0c72926f4: stopping tablet replica
I20260812 06:17:58.811517 11384 master.cc:584] Master@127.11.30.62:38153 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5190 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10446 ms total)

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