[==========] 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:11.951946 30341 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.29.161.126:35119
I20260812 06:17:11.953096 30341 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:11.953853 30341 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:11.961678 30349 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:11.961705 30352 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:11.961896 30341 server_base.cc:1061] running on GCE node
W20260812 06:17:11.962097 30348 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:11.962693 30341 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:11.962824 30341 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:11.962872 30341 hybrid_clock.cc:648] HybridClock initialized: now 1786515431962868 us; error 0 us; skew 500 ppm
I20260812 06:17:11.964854 30341 webserver.cc:533] Webserver started at http://127.29.161.126:39715/ using document root <none> and password file <none>
I20260812 06:17:11.965519 30341 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:11.965610 30341 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:11.965927 30341 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:11.967777 30341 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431940255-30341-0/minicluster-data/master-0-root/instance:
uuid: "648895127e5c476bbc7fcef62b44ecb1"
format_stamp: "Formatted at 2026-08-12 06:17:11 on dist-test-slave-0kls"
I20260812 06:17:11.971832 30341 fs_manager.cc:696] Time spent creating directory manager: real 0.004s	user 0.005s	sys 0.000s
I20260812 06:17:11.974287 30358 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:11.975446 30341 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:17:11.975596 30341 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431940255-30341-0/minicluster-data/master-0-root
uuid: "648895127e5c476bbc7fcef62b44ecb1"
format_stamp: "Formatted at 2026-08-12 06:17:11 on dist-test-slave-0kls"
I20260812 06:17:11.975720 30341 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431940255-30341-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431940255-30341-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431940255-30341-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:12.012821 30341 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:12.013674 30341 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:12.013958 30341 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:12.023123 30341 rpc_server.cc:307] RPC server started. Bound to: 127.29.161.126:35119
I20260812 06:17:12.023144 30422 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.29.161.126:35119 every 8 connection(s)
I20260812 06:17:12.025736 30423 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:12.031772 30423 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 648895127e5c476bbc7fcef62b44ecb1: Bootstrap starting.
I20260812 06:17:12.034452 30423 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 648895127e5c476bbc7fcef62b44ecb1: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:12.035488 30423 log.cc:826] T 00000000000000000000000000000000 P 648895127e5c476bbc7fcef62b44ecb1: Log is configured to *not* fsync() on all Append() calls
I20260812 06:17:12.037539 30423 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 648895127e5c476bbc7fcef62b44ecb1: No bootstrap required, opened a new log
I20260812 06:17:12.040594 30423 raft_consensus.cc:359] T 00000000000000000000000000000000 P 648895127e5c476bbc7fcef62b44ecb1 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "648895127e5c476bbc7fcef62b44ecb1" member_type: VOTER }
I20260812 06:17:12.040793 30423 raft_consensus.cc:385] T 00000000000000000000000000000000 P 648895127e5c476bbc7fcef62b44ecb1 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:12.040876 30423 raft_consensus.cc:740] T 00000000000000000000000000000000 P 648895127e5c476bbc7fcef62b44ecb1 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 648895127e5c476bbc7fcef62b44ecb1, State: Initialized, Role: FOLLOWER
I20260812 06:17:12.041534 30423 consensus_queue.cc:260] T 00000000000000000000000000000000 P 648895127e5c476bbc7fcef62b44ecb1 [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: "648895127e5c476bbc7fcef62b44ecb1" member_type: VOTER }
I20260812 06:17:12.041699 30423 raft_consensus.cc:399] T 00000000000000000000000000000000 P 648895127e5c476bbc7fcef62b44ecb1 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:12.041860 30423 raft_consensus.cc:493] T 00000000000000000000000000000000 P 648895127e5c476bbc7fcef62b44ecb1 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:12.042021 30423 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 648895127e5c476bbc7fcef62b44ecb1 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:12.042955 30423 raft_consensus.cc:515] T 00000000000000000000000000000000 P 648895127e5c476bbc7fcef62b44ecb1 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "648895127e5c476bbc7fcef62b44ecb1" member_type: VOTER }
I20260812 06:17:12.043466 30423 leader_election.cc:304] T 00000000000000000000000000000000 P 648895127e5c476bbc7fcef62b44ecb1 [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: 648895127e5c476bbc7fcef62b44ecb1; no voters: 
I20260812 06:17:12.043836 30423 leader_election.cc:290] T 00000000000000000000000000000000 P 648895127e5c476bbc7fcef62b44ecb1 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:12.044018 30426 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 648895127e5c476bbc7fcef62b44ecb1 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:12.044299 30426 raft_consensus.cc:697] T 00000000000000000000000000000000 P 648895127e5c476bbc7fcef62b44ecb1 [term 1 LEADER]: Becoming Leader. State: Replica: 648895127e5c476bbc7fcef62b44ecb1, State: Running, Role: LEADER
I20260812 06:17:12.044756 30426 consensus_queue.cc:237] T 00000000000000000000000000000000 P 648895127e5c476bbc7fcef62b44ecb1 [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: "648895127e5c476bbc7fcef62b44ecb1" member_type: VOTER }
I20260812 06:17:12.044950 30423 sys_catalog.cc:565] T 00000000000000000000000000000000 P 648895127e5c476bbc7fcef62b44ecb1 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:12.046722 30428 sys_catalog.cc:455] T 00000000000000000000000000000000 P 648895127e5c476bbc7fcef62b44ecb1 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 648895127e5c476bbc7fcef62b44ecb1. Latest consensus state: current_term: 1 leader_uuid: "648895127e5c476bbc7fcef62b44ecb1" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "648895127e5c476bbc7fcef62b44ecb1" member_type: VOTER } }
I20260812 06:17:12.046762 30427 sys_catalog.cc:455] T 00000000000000000000000000000000 P 648895127e5c476bbc7fcef62b44ecb1 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "648895127e5c476bbc7fcef62b44ecb1" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "648895127e5c476bbc7fcef62b44ecb1" member_type: VOTER } }
I20260812 06:17:12.046861 30428 sys_catalog.cc:458] T 00000000000000000000000000000000 P 648895127e5c476bbc7fcef62b44ecb1 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:12.046861 30427 sys_catalog.cc:458] T 00000000000000000000000000000000 P 648895127e5c476bbc7fcef62b44ecb1 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:12.047358 30439 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:12.047613 30341 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:12.050282 30439 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:12.055657 30439 catalog_manager.cc:1383] Generated new cluster ID: a8d6880ddd0c43608e5dbf2cb17f928e
I20260812 06:17:12.055773 30439 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:12.071557 30439 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:12.072511 30439 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:12.078912 30439 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 648895127e5c476bbc7fcef62b44ecb1: Generated new TSK 0
I20260812 06:17:12.079730 30439 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:12.112684 30341 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:12.115892 30447 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:12.116014 30449 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:12.116175 30341 server_base.cc:1061] running on GCE node
W20260812 06:17:12.116014 30451 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:12.116469 30341 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:12.116532 30341 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:12.116556 30341 hybrid_clock.cc:648] HybridClock initialized: now 1786515432116556 us; error 0 us; skew 500 ppm
I20260812 06:17:12.117612 30341 webserver.cc:533] Webserver started at http://127.29.161.65:44323/ using document root <none> and password file <none>
I20260812 06:17:12.117827 30341 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:12.117889 30341 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:12.117969 30341 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:12.118430 30341 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431940255-30341-0/minicluster-data/ts-0-root/instance:
uuid: "0414c4f10eb24d4badaf7b745880c39a"
format_stamp: "Formatted at 2026-08-12 06:17:12 on dist-test-slave-0kls"
I20260812 06:17:12.120378 30341 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:12.121672 30456 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:12.122064 30341 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:12.122150 30341 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431940255-30341-0/minicluster-data/ts-0-root
uuid: "0414c4f10eb24d4badaf7b745880c39a"
format_stamp: "Formatted at 2026-08-12 06:17:12 on dist-test-slave-0kls"
I20260812 06:17:12.122231 30341 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431940255-30341-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431940255-30341-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431940255-30341-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:12.130474 30341 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:12.131040 30341 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:12.131605 30341 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:12.132675 30341 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:12.132754 30341 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:12.132817 30341 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:12.132841 30341 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:12.140043 30341 rpc_server.cc:307] RPC server started. Bound to: 127.29.161.65:45743
I20260812 06:17:12.140127 30528 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.29.161.65:45743 every 8 connection(s)
I20260812 06:17:12.151711 30529 heartbeater.cc:344] Connected to a master server at 127.29.161.126:35119
I20260812 06:17:12.152009 30529 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:12.152489 30529 heartbeater.cc:507] Master 127.29.161.126:35119 requested a full tablet report, sending...
I20260812 06:17:12.154096 30379 ts_manager.cc:194] Registered new tserver with Master: 0414c4f10eb24d4badaf7b745880c39a (127.29.161.65:45743)
I20260812 06:17:12.154197 30341 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.013415614s
I20260812 06:17:12.155369 30379 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:41306
I20260812 06:17:12.164373 30379 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:41312:
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:12.179281 30489 tablet_service.cc:1511] Processing CreateTablet for tablet fa0626524a414e1fb9312a4008f2ea05 (DEFAULT_TABLE table=heavy-update-compaction-test [id=756a2e13e7814d4d986cd43fb5b518bf]), partition=
I20260812 06:17:12.179951 30489 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet fa0626524a414e1fb9312a4008f2ea05. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:12.183051 30543 tablet_bootstrap.cc:492] T fa0626524a414e1fb9312a4008f2ea05 P 0414c4f10eb24d4badaf7b745880c39a: Bootstrap starting.
I20260812 06:17:12.184698 30543 tablet_bootstrap.cc:654] T fa0626524a414e1fb9312a4008f2ea05 P 0414c4f10eb24d4badaf7b745880c39a: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:12.186265 30543 tablet_bootstrap.cc:492] T fa0626524a414e1fb9312a4008f2ea05 P 0414c4f10eb24d4badaf7b745880c39a: No bootstrap required, opened a new log
I20260812 06:17:12.186431 30543 ts_tablet_manager.cc:1403] T fa0626524a414e1fb9312a4008f2ea05 P 0414c4f10eb24d4badaf7b745880c39a: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:17:12.187254 30543 raft_consensus.cc:359] T fa0626524a414e1fb9312a4008f2ea05 P 0414c4f10eb24d4badaf7b745880c39a [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0414c4f10eb24d4badaf7b745880c39a" member_type: VOTER last_known_addr { host: "127.29.161.65" port: 45743 } }
I20260812 06:17:12.187418 30543 raft_consensus.cc:385] T fa0626524a414e1fb9312a4008f2ea05 P 0414c4f10eb24d4badaf7b745880c39a [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:12.187480 30543 raft_consensus.cc:740] T fa0626524a414e1fb9312a4008f2ea05 P 0414c4f10eb24d4badaf7b745880c39a [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 0414c4f10eb24d4badaf7b745880c39a, State: Initialized, Role: FOLLOWER
I20260812 06:17:12.187659 30543 consensus_queue.cc:260] T fa0626524a414e1fb9312a4008f2ea05 P 0414c4f10eb24d4badaf7b745880c39a [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: "0414c4f10eb24d4badaf7b745880c39a" member_type: VOTER last_known_addr { host: "127.29.161.65" port: 45743 } }
I20260812 06:17:12.187819 30543 raft_consensus.cc:399] T fa0626524a414e1fb9312a4008f2ea05 P 0414c4f10eb24d4badaf7b745880c39a [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:12.187880 30543 raft_consensus.cc:493] T fa0626524a414e1fb9312a4008f2ea05 P 0414c4f10eb24d4badaf7b745880c39a [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:12.187940 30543 raft_consensus.cc:3060] T fa0626524a414e1fb9312a4008f2ea05 P 0414c4f10eb24d4badaf7b745880c39a [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:12.188843 30543 raft_consensus.cc:515] T fa0626524a414e1fb9312a4008f2ea05 P 0414c4f10eb24d4badaf7b745880c39a [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0414c4f10eb24d4badaf7b745880c39a" member_type: VOTER last_known_addr { host: "127.29.161.65" port: 45743 } }
I20260812 06:17:12.189020 30543 leader_election.cc:304] T fa0626524a414e1fb9312a4008f2ea05 P 0414c4f10eb24d4badaf7b745880c39a [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: 0414c4f10eb24d4badaf7b745880c39a; no voters: 
I20260812 06:17:12.189332 30543 leader_election.cc:290] T fa0626524a414e1fb9312a4008f2ea05 P 0414c4f10eb24d4badaf7b745880c39a [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:12.189456 30545 raft_consensus.cc:2804] T fa0626524a414e1fb9312a4008f2ea05 P 0414c4f10eb24d4badaf7b745880c39a [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:12.189761 30545 raft_consensus.cc:697] T fa0626524a414e1fb9312a4008f2ea05 P 0414c4f10eb24d4badaf7b745880c39a [term 1 LEADER]: Becoming Leader. State: Replica: 0414c4f10eb24d4badaf7b745880c39a, State: Running, Role: LEADER
I20260812 06:17:12.189826 30543 ts_tablet_manager.cc:1434] T fa0626524a414e1fb9312a4008f2ea05 P 0414c4f10eb24d4badaf7b745880c39a: Time spent starting tablet: real 0.003s	user 0.000s	sys 0.004s
I20260812 06:17:12.190039 30529 heartbeater.cc:499] Master 127.29.161.126:35119 was elected leader, sending a full tablet report...
I20260812 06:17:12.190279 30545 consensus_queue.cc:237] T fa0626524a414e1fb9312a4008f2ea05 P 0414c4f10eb24d4badaf7b745880c39a [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: "0414c4f10eb24d4badaf7b745880c39a" member_type: VOTER last_known_addr { host: "127.29.161.65" port: 45743 } }
I20260812 06:17:12.193467 30378 catalog_manager.cc:5719] T fa0626524a414e1fb9312a4008f2ea05 P 0414c4f10eb24d4badaf7b745880c39a reported cstate change: term changed from 0 to 1, leader changed from <none> to 0414c4f10eb24d4badaf7b745880c39a (127.29.161.65). New cstate: current_term: 1 leader_uuid: "0414c4f10eb24d4badaf7b745880c39a" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0414c4f10eb24d4badaf7b745880c39a" member_type: VOTER last_known_addr { host: "127.29.161.65" port: 45743 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:12.270905 30341 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.068s	user 0.023s	sys 0.012s
I20260812 06:17:12.391413 30530 maintenance_manager.cc:419] P 0414c4f10eb24d4badaf7b745880c39a: Scheduling FlushMRSOp(fa0626524a414e1fb9312a4008f2ea05): perf score=15.086190
I20260812 06:17:12.560693 30461 maintenance_manager.cc:643] P 0414c4f10eb24d4badaf7b745880c39a: FlushMRSOp(fa0626524a414e1fb9312a4008f2ea05) complete. Timing: real 0.169s	user 0.133s	sys 0.032s Metrics: {"bytes_written":12307490,"cfile_init":1,"compiler_manager_pool.queue_time_us":255,"delete_count":0,"dirs.queue_time_us":135,"dirs.run_cpu_time_us":259,"dirs.run_wall_time_us":1028,"drs_written":1,"lbm_read_time_us":77,"lbm_reads_lt_1ms":4,"lbm_write_time_us":41166,"lbm_writes_lt_1ms":657,"peak_mem_usage":0,"reinsert_count":0,"rows_written":103,"thread_start_us":149,"threads_started":1,"update_count":1500}
I20260812 06:17:12.562201 30530 maintenance_manager.cc:419] P 0414c4f10eb24d4badaf7b745880c39a: Scheduling LogGCOp(fa0626524a414e1fb9312a4008f2ea05): free 11976772 bytes of WAL
I20260812 06:17:12.562542 30461 log_reader.cc:385] T fa0626524a414e1fb9312a4008f2ea05: removed 1 log segments from log reader
I20260812 06:17:12.562608 30461 log.cc:1079] T fa0626524a414e1fb9312a4008f2ea05 P 0414c4f10eb24d4badaf7b745880c39a: Deleting log segment in path: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431940255-30341-0/minicluster-data/ts-0-root/wals/fa0626524a414e1fb9312a4008f2ea05/wal-000000001 (ops 1-6)
I20260812 06:17:12.566182 30461 maintenance_manager.cc:643] P 0414c4f10eb24d4badaf7b745880c39a: LogGCOp(fa0626524a414e1fb9312a4008f2ea05) complete. Timing: real 0.004s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:17:12.566653 30530 maintenance_manager.cc:419] P 0414c4f10eb24d4badaf7b745880c39a: Scheduling FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05): perf score=2.188937
I20260812 06:17:12.594049 30461 maintenance_manager.cc:643] P 0414c4f10eb24d4badaf7b745880c39a: FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05) complete. Timing: real 0.027s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5601,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:12.594614 30530 maintenance_manager.cc:419] P 0414c4f10eb24d4badaf7b745880c39a: Scheduling UndoDeltaBlockGCOp(fa0626524a414e1fb9312a4008f2ea05): 12308958 bytes on disk
I20260812 06:17:12.595314 30461 maintenance_manager.cc:643] P 0414c4f10eb24d4badaf7b745880c39a: UndoDeltaBlockGCOp(fa0626524a414e1fb9312a4008f2ea05) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":74,"lbm_reads_lt_1ms":4}
I20260812 06:17:12.595814 30530 maintenance_manager.cc:419] P 0414c4f10eb24d4badaf7b745880c39a: Scheduling FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05): perf score=2.188937
I20260812 06:17:12.611788 30461 maintenance_manager.cc:643] P 0414c4f10eb24d4badaf7b745880c39a: FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05) complete. Timing: real 0.016s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6239,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:12.612344 30530 maintenance_manager.cc:419] P 0414c4f10eb24d4badaf7b745880c39a: Scheduling MajorDeltaCompactionOp(fa0626524a414e1fb9312a4008f2ea05): perf score=1.000000
I20260812 06:17:12.787267 30461 maintenance_manager.cc:643] P 0414c4f10eb24d4badaf7b745880c39a: MajorDeltaCompactionOp(fa0626524a414e1fb9312a4008f2ea05) complete. Timing: real 0.175s	user 0.127s	sys 0.045s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24733842,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":874,"lbm_read_time_us":11700,"lbm_reads_lt_1ms":569,"lbm_write_time_us":31150,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2176,"thread_start_us":371,"threads_started":5,"update_count":2500}
I20260812 06:17:12.787935 30530 maintenance_manager.cc:419] P 0414c4f10eb24d4badaf7b745880c39a: Scheduling FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05): perf score=10.126437
I20260812 06:17:12.824440 30461 maintenance_manager.cc:643] P 0414c4f10eb24d4badaf7b745880c39a: FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05) complete. Timing: real 0.036s	user 0.025s	sys 0.008s Metrics: {"bytes_written":12307494,"delete_count":0,"lbm_write_time_us":15630,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:12.824944 30530 maintenance_manager.cc:419] P 0414c4f10eb24d4badaf7b745880c39a: Scheduling FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05): perf score=2.188937
I20260812 06:17:12.841424 30461 maintenance_manager.cc:643] P 0414c4f10eb24d4badaf7b745880c39a: FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05) complete. Timing: real 0.016s	user 0.002s	sys 0.011s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5950,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:12.841976 30530 maintenance_manager.cc:419] P 0414c4f10eb24d4badaf7b745880c39a: Scheduling MajorDeltaCompactionOp(fa0626524a414e1fb9312a4008f2ea05): perf score=1.000000
I20260812 06:17:12.971191 30461 maintenance_manager.cc:643] P 0414c4f10eb24d4badaf7b745880c39a: MajorDeltaCompactionOp(fa0626524a414e1fb9312a4008f2ea05) complete. Timing: real 0.129s	user 0.096s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631315,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":601,"lbm_read_time_us":8622,"lbm_reads_lt_1ms":464,"lbm_write_time_us":25534,"lbm_writes_lt_1ms":443,"mutex_wait_us":25,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3840,"update_count":2000}
I20260812 06:17:12.971738 30530 maintenance_manager.cc:419] P 0414c4f10eb24d4badaf7b745880c39a: Scheduling FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05): perf score=10.126437
I20260812 06:17:13.009569 30461 maintenance_manager.cc:643] P 0414c4f10eb24d4badaf7b745880c39a: FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05) complete. Timing: real 0.038s	user 0.022s	sys 0.011s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17586,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:17:13.010218 30530 maintenance_manager.cc:419] P 0414c4f10eb24d4badaf7b745880c39a: Scheduling FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05): perf score=2.188937
I20260812 06:17:13.026453 30461 maintenance_manager.cc:643] P 0414c4f10eb24d4badaf7b745880c39a: FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05) complete. Timing: real 0.016s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6283,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:13.026948 30530 maintenance_manager.cc:419] P 0414c4f10eb24d4badaf7b745880c39a: Scheduling MajorDeltaCompactionOp(fa0626524a414e1fb9312a4008f2ea05): perf score=1.000000
I20260812 06:17:13.165922 30461 maintenance_manager.cc:643] P 0414c4f10eb24d4badaf7b745880c39a: MajorDeltaCompactionOp(fa0626524a414e1fb9312a4008f2ea05) complete. Timing: real 0.139s	user 0.105s	sys 0.034s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631313,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":480,"lbm_read_time_us":9857,"lbm_reads_lt_1ms":464,"lbm_write_time_us":27578,"lbm_writes_lt_1ms":443,"mutex_wait_us":87,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":15488,"update_count":2000}
I20260812 06:17:13.166643 30530 maintenance_manager.cc:419] P 0414c4f10eb24d4badaf7b745880c39a: Scheduling FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05): perf score=10.126437
I20260812 06:17:13.217672 30461 maintenance_manager.cc:643] P 0414c4f10eb24d4badaf7b745880c39a: FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05) complete. Timing: real 0.051s	user 0.023s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15270,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:13.218374 30530 maintenance_manager.cc:419] P 0414c4f10eb24d4badaf7b745880c39a: Scheduling FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05): perf score=2.188937
I20260812 06:17:13.229526 30461 maintenance_manager.cc:643] P 0414c4f10eb24d4badaf7b745880c39a: FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4374,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:13.230041 30530 maintenance_manager.cc:419] P 0414c4f10eb24d4badaf7b745880c39a: Scheduling MajorDeltaCompactionOp(fa0626524a414e1fb9312a4008f2ea05): perf score=1.000000
I20260812 06:17:13.395046 30461 maintenance_manager.cc:643] P 0414c4f10eb24d4badaf7b745880c39a: MajorDeltaCompactionOp(fa0626524a414e1fb9312a4008f2ea05) complete. Timing: real 0.165s	user 0.130s	sys 0.027s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631311,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":259,"lbm_read_time_us":10898,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26693,"lbm_writes_lt_1ms":443,"mutex_wait_us":30,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:13.395735 30530 maintenance_manager.cc:419] P 0414c4f10eb24d4badaf7b745880c39a: Scheduling FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05): perf score=10.126437
I20260812 06:17:13.444391 30461 maintenance_manager.cc:643] P 0414c4f10eb24d4badaf7b745880c39a: FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05) complete. Timing: real 0.048s	user 0.021s	sys 0.013s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16024,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:13.445004 30530 maintenance_manager.cc:419] P 0414c4f10eb24d4badaf7b745880c39a: Scheduling FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05): perf score=2.188937
I20260812 06:17:13.458788 30461 maintenance_manager.cc:643] P 0414c4f10eb24d4badaf7b745880c39a: FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05) complete. Timing: real 0.014s	user 0.009s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4834,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:13.459571 30530 maintenance_manager.cc:419] P 0414c4f10eb24d4badaf7b745880c39a: Scheduling MajorDeltaCompactionOp(fa0626524a414e1fb9312a4008f2ea05): perf score=1.000000
I20260812 06:17:13.594520 30461 maintenance_manager.cc:643] P 0414c4f10eb24d4badaf7b745880c39a: MajorDeltaCompactionOp(fa0626524a414e1fb9312a4008f2ea05) complete. Timing: real 0.135s	user 0.111s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":237,"lbm_read_time_us":8800,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24560,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:13.595032 30530 maintenance_manager.cc:419] P 0414c4f10eb24d4badaf7b745880c39a: Scheduling FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05): perf score=10.126437
I20260812 06:17:13.639000 30461 maintenance_manager.cc:643] P 0414c4f10eb24d4badaf7b745880c39a: FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05) complete. Timing: real 0.044s	user 0.018s	sys 0.024s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":18352,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:13.639539 30530 maintenance_manager.cc:419] P 0414c4f10eb24d4badaf7b745880c39a: Scheduling FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05): perf score=2.188937
I20260812 06:17:13.651628 30461 maintenance_manager.cc:643] P 0414c4f10eb24d4badaf7b745880c39a: FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05) complete. Timing: real 0.012s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4361,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:13.652150 30530 maintenance_manager.cc:419] P 0414c4f10eb24d4badaf7b745880c39a: Scheduling MajorDeltaCompactionOp(fa0626524a414e1fb9312a4008f2ea05): perf score=1.000000
I20260812 06:17:13.775055 30461 maintenance_manager.cc:643] P 0414c4f10eb24d4badaf7b745880c39a: MajorDeltaCompactionOp(fa0626524a414e1fb9312a4008f2ea05) complete. Timing: real 0.123s	user 0.096s	sys 0.025s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631311,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":229,"lbm_read_time_us":8726,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23503,"lbm_writes_lt_1ms":443,"mutex_wait_us":2,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:13.775645 30530 maintenance_manager.cc:419] P 0414c4f10eb24d4badaf7b745880c39a: Scheduling FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05): perf score=10.126437
I20260812 06:17:13.825076 30461 maintenance_manager.cc:643] P 0414c4f10eb24d4badaf7b745880c39a: FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05) complete. Timing: real 0.049s	user 0.017s	sys 0.024s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":16154,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:13.825700 30530 maintenance_manager.cc:419] P 0414c4f10eb24d4badaf7b745880c39a: Scheduling FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05): perf score=2.188937
I20260812 06:17:13.837149 30461 maintenance_manager.cc:643] P 0414c4f10eb24d4badaf7b745880c39a: FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4214,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:13.837764 30530 maintenance_manager.cc:419] P 0414c4f10eb24d4badaf7b745880c39a: Scheduling FlushMRSOp(fa0626524a414e1fb9312a4008f2ea05): perf score=1.000000
I20260812 06:17:13.884398 30461 maintenance_manager.cc:643] P 0414c4f10eb24d4badaf7b745880c39a: FlushMRSOp(fa0626524a414e1fb9312a4008f2ea05) complete. Timing: real 0.046s	user 0.031s	sys 0.001s Metrics: {"bytes_written":1193504,"cfile_init":1,"dirs.queue_time_us":93,"dirs.run_cpu_time_us":310,"dirs.run_wall_time_us":1573,"drs_written":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2412,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:17:13.885265 30530 maintenance_manager.cc:419] P 0414c4f10eb24d4badaf7b745880c39a: Scheduling LogGCOp(fa0626524a414e1fb9312a4008f2ea05): free 121006420 bytes of WAL
I20260812 06:17:13.885514 30461 log_reader.cc:385] T fa0626524a414e1fb9312a4008f2ea05: removed 12 log segments from log reader
I20260812 06:17:13.885582 30461 log.cc:1079] T fa0626524a414e1fb9312a4008f2ea05 P 0414c4f10eb24d4badaf7b745880c39a: Deleting log segment in path: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431940255-30341-0/minicluster-data/ts-0-root/wals/fa0626524a414e1fb9312a4008f2ea05/wal-000000002 (ops 7-11)
I20260812 06:17:13.885643 30461 log.cc:1079] T fa0626524a414e1fb9312a4008f2ea05 P 0414c4f10eb24d4badaf7b745880c39a: Deleting log segment in path: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431940255-30341-0/minicluster-data/ts-0-root/wals/fa0626524a414e1fb9312a4008f2ea05/wal-000000003 (ops 12-16)
I20260812 06:17:13.885681 30461 log.cc:1079] T fa0626524a414e1fb9312a4008f2ea05 P 0414c4f10eb24d4badaf7b745880c39a: Deleting log segment in path: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431940255-30341-0/minicluster-data/ts-0-root/wals/fa0626524a414e1fb9312a4008f2ea05/wal-000000004 (ops 17-20)
I20260812 06:17:13.885715 30461 log.cc:1079] T fa0626524a414e1fb9312a4008f2ea05 P 0414c4f10eb24d4badaf7b745880c39a: Deleting log segment in path: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431940255-30341-0/minicluster-data/ts-0-root/wals/fa0626524a414e1fb9312a4008f2ea05/wal-000000005 (ops 21-25)
I20260812 06:17:13.885752 30461 log.cc:1079] T fa0626524a414e1fb9312a4008f2ea05 P 0414c4f10eb24d4badaf7b745880c39a: Deleting log segment in path: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431940255-30341-0/minicluster-data/ts-0-root/wals/fa0626524a414e1fb9312a4008f2ea05/wal-000000006 (ops 26-30)
I20260812 06:17:13.885820 30461 log.cc:1079] T fa0626524a414e1fb9312a4008f2ea05 P 0414c4f10eb24d4badaf7b745880c39a: Deleting log segment in path: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431940255-30341-0/minicluster-data/ts-0-root/wals/fa0626524a414e1fb9312a4008f2ea05/wal-000000007 (ops 31-35)
I20260812 06:17:13.885857 30461 log.cc:1079] T fa0626524a414e1fb9312a4008f2ea05 P 0414c4f10eb24d4badaf7b745880c39a: Deleting log segment in path: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431940255-30341-0/minicluster-data/ts-0-root/wals/fa0626524a414e1fb9312a4008f2ea05/wal-000000008 (ops 36-40)
I20260812 06:17:13.885892 30461 log.cc:1079] T fa0626524a414e1fb9312a4008f2ea05 P 0414c4f10eb24d4badaf7b745880c39a: Deleting log segment in path: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431940255-30341-0/minicluster-data/ts-0-root/wals/fa0626524a414e1fb9312a4008f2ea05/wal-000000009 (ops 41-45)
I20260812 06:17:13.885929 30461 log.cc:1079] T fa0626524a414e1fb9312a4008f2ea05 P 0414c4f10eb24d4badaf7b745880c39a: Deleting log segment in path: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431940255-30341-0/minicluster-data/ts-0-root/wals/fa0626524a414e1fb9312a4008f2ea05/wal-000000010 (ops 46-50)
I20260812 06:17:13.885969 30461 log.cc:1079] T fa0626524a414e1fb9312a4008f2ea05 P 0414c4f10eb24d4badaf7b745880c39a: Deleting log segment in path: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431940255-30341-0/minicluster-data/ts-0-root/wals/fa0626524a414e1fb9312a4008f2ea05/wal-000000011 (ops 51-55)
I20260812 06:17:13.886008 30461 log.cc:1079] T fa0626524a414e1fb9312a4008f2ea05 P 0414c4f10eb24d4badaf7b745880c39a: Deleting log segment in path: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431940255-30341-0/minicluster-data/ts-0-root/wals/fa0626524a414e1fb9312a4008f2ea05/wal-000000012 (ops 56-60)
I20260812 06:17:13.886049 30461 log.cc:1079] T fa0626524a414e1fb9312a4008f2ea05 P 0414c4f10eb24d4badaf7b745880c39a: Deleting log segment in path: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431940255-30341-0/minicluster-data/ts-0-root/wals/fa0626524a414e1fb9312a4008f2ea05/wal-000000013 (ops 61-65)
I20260812 06:17:13.914029 30461 maintenance_manager.cc:643] P 0414c4f10eb24d4badaf7b745880c39a: LogGCOp(fa0626524a414e1fb9312a4008f2ea05) complete. Timing: real 0.029s	user 0.000s	sys 0.028s Metrics: {}
I20260812 06:17:13.914618 30530 maintenance_manager.cc:419] P 0414c4f10eb24d4badaf7b745880c39a: Scheduling FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05): perf score=3.181125
I20260812 06:17:13.932679 30461 maintenance_manager.cc:643] P 0414c4f10eb24d4badaf7b745880c39a: FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05) complete. Timing: real 0.018s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4593,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:13.933393 30530 maintenance_manager.cc:419] P 0414c4f10eb24d4badaf7b745880c39a: Scheduling FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05): perf score=2.188937
I20260812 06:17:13.947484 30461 maintenance_manager.cc:643] P 0414c4f10eb24d4badaf7b745880c39a: FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05) complete. Timing: real 0.014s	user 0.012s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5223,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:13.948010 30530 maintenance_manager.cc:419] P 0414c4f10eb24d4badaf7b745880c39a: Scheduling UndoDeltaBlockGCOp(fa0626524a414e1fb9312a4008f2ea05): 463 bytes on disk
I20260812 06:17:13.948475 30461 maintenance_manager.cc:643] P 0414c4f10eb24d4badaf7b745880c39a: UndoDeltaBlockGCOp(fa0626524a414e1fb9312a4008f2ea05) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":60,"lbm_reads_lt_1ms":4}
I20260812 06:17:13.948953 30530 maintenance_manager.cc:419] P 0414c4f10eb24d4badaf7b745880c39a: Scheduling MajorDeltaCompactionOp(fa0626524a414e1fb9312a4008f2ea05): perf score=1.000000
I20260812 06:17:14.171001 30461 maintenance_manager.cc:643] P 0414c4f10eb24d4badaf7b745880c39a: MajorDeltaCompactionOp(fa0626524a414e1fb9312a4008f2ea05) complete. Timing: real 0.222s	user 0.160s	sys 0.055s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836366,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1059,"lbm_read_time_us":13840,"lbm_reads_lt_1ms":674,"lbm_write_time_us":36875,"lbm_writes_lt_1ms":643,"mutex_wait_us":627,"peak_mem_usage":75542472,"reinsert_count":0,"thread_start_us":86,"threads_started":1,"update_count":3000}
I20260812 06:17:14.171757 30530 maintenance_manager.cc:419] P 0414c4f10eb24d4badaf7b745880c39a: Scheduling FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05): perf score=14.095187
I20260812 06:17:14.218964 30461 maintenance_manager.cc:643] P 0414c4f10eb24d4badaf7b745880c39a: FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05) complete. Timing: real 0.047s	user 0.030s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20427,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:14.219544 30530 maintenance_manager.cc:419] P 0414c4f10eb24d4badaf7b745880c39a: Scheduling MajorDeltaCompactionOp(fa0626524a414e1fb9312a4008f2ea05): perf score=1.000000
I20260812 06:17:14.370460 30461 maintenance_manager.cc:643] P 0414c4f10eb24d4badaf7b745880c39a: MajorDeltaCompactionOp(fa0626524a414e1fb9312a4008f2ea05) complete. Timing: real 0.151s	user 0.127s	sys 0.024s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20631193,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":62,"lbm_read_time_us":9442,"lbm_reads_lt_1ms":467,"lbm_write_time_us":25505,"lbm_writes_lt_1ms":443,"mutex_wait_us":26,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2000}
I20260812 06:17:14.371119 30530 maintenance_manager.cc:419] P 0414c4f10eb24d4badaf7b745880c39a: Scheduling FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05): perf score=10.126437
I20260812 06:17:14.404178 30461 maintenance_manager.cc:643] P 0414c4f10eb24d4badaf7b745880c39a: FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05) complete. Timing: real 0.033s	user 0.013s	sys 0.017s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":14091,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:14.404838 30530 maintenance_manager.cc:419] P 0414c4f10eb24d4badaf7b745880c39a: Scheduling FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05): perf score=2.188937
I20260812 06:17:14.416684 30461 maintenance_manager.cc:643] P 0414c4f10eb24d4badaf7b745880c39a: FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4118,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:14.417165 30530 maintenance_manager.cc:419] P 0414c4f10eb24d4badaf7b745880c39a: Scheduling MajorDeltaCompactionOp(fa0626524a414e1fb9312a4008f2ea05): perf score=1.000000
I20260812 06:17:14.559005 30461 maintenance_manager.cc:643] P 0414c4f10eb24d4badaf7b745880c39a: MajorDeltaCompactionOp(fa0626524a414e1fb9312a4008f2ea05) complete. Timing: real 0.142s	user 0.114s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631313,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":144,"lbm_read_time_us":9512,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26408,"lbm_writes_lt_1ms":443,"mutex_wait_us":30,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":90112,"update_count":2000}
I20260812 06:17:14.559815 30530 maintenance_manager.cc:419] P 0414c4f10eb24d4badaf7b745880c39a: Scheduling FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05): perf score=10.126437
I20260812 06:17:14.604929 30461 maintenance_manager.cc:643] P 0414c4f10eb24d4badaf7b745880c39a: FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05) complete. Timing: real 0.045s	user 0.011s	sys 0.027s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":20421,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:17:14.605453 30530 maintenance_manager.cc:419] P 0414c4f10eb24d4badaf7b745880c39a: Scheduling FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05): perf score=2.188937
I20260812 06:17:14.616544 30461 maintenance_manager.cc:643] P 0414c4f10eb24d4badaf7b745880c39a: FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4092,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:14.617302 30530 maintenance_manager.cc:419] P 0414c4f10eb24d4badaf7b745880c39a: Scheduling MajorDeltaCompactionOp(fa0626524a414e1fb9312a4008f2ea05): perf score=1.000000
I20260812 06:17:14.749660 30461 maintenance_manager.cc:643] P 0414c4f10eb24d4badaf7b745880c39a: MajorDeltaCompactionOp(fa0626524a414e1fb9312a4008f2ea05) complete. Timing: real 0.132s	user 0.091s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631311,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":630,"lbm_read_time_us":9877,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25620,"lbm_writes_lt_1ms":443,"mutex_wait_us":27,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":21888,"update_count":2000}
I20260812 06:17:14.750653 30530 maintenance_manager.cc:419] P 0414c4f10eb24d4badaf7b745880c39a: Scheduling FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05): perf score=10.126437
I20260812 06:17:14.790270 30461 maintenance_manager.cc:643] P 0414c4f10eb24d4badaf7b745880c39a: FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05) complete. Timing: real 0.039s	user 0.032s	sys 0.007s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16708,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:14.790824 30530 maintenance_manager.cc:419] P 0414c4f10eb24d4badaf7b745880c39a: Scheduling FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05): perf score=2.188937
I20260812 06:17:14.807866 30461 maintenance_manager.cc:643] P 0414c4f10eb24d4badaf7b745880c39a: FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05) complete. Timing: real 0.017s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6377,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:14.808480 30530 maintenance_manager.cc:419] P 0414c4f10eb24d4badaf7b745880c39a: Scheduling MajorDeltaCompactionOp(fa0626524a414e1fb9312a4008f2ea05): perf score=1.000000
I20260812 06:17:14.938408 30461 maintenance_manager.cc:643] P 0414c4f10eb24d4badaf7b745880c39a: MajorDeltaCompactionOp(fa0626524a414e1fb9312a4008f2ea05) complete. Timing: real 0.130s	user 0.106s	sys 0.023s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631311,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":539,"lbm_read_time_us":7916,"lbm_reads_lt_1ms":464,"lbm_write_time_us":27137,"lbm_writes_lt_1ms":443,"mutex_wait_us":20,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":15744,"update_count":2000}
I20260812 06:17:14.939101 30530 maintenance_manager.cc:419] P 0414c4f10eb24d4badaf7b745880c39a: Scheduling FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05): perf score=10.126437
I20260812 06:17:14.985623 30461 maintenance_manager.cc:643] P 0414c4f10eb24d4badaf7b745880c39a: FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05) complete. Timing: real 0.046s	user 0.016s	sys 0.024s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14296,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:14.986335 30530 maintenance_manager.cc:419] P 0414c4f10eb24d4badaf7b745880c39a: Scheduling FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05): perf score=2.188937
I20260812 06:17:14.998638 30461 maintenance_manager.cc:643] P 0414c4f10eb24d4badaf7b745880c39a: FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05) complete. Timing: real 0.012s	user 0.006s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4724,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:14.999173 30530 maintenance_manager.cc:419] P 0414c4f10eb24d4badaf7b745880c39a: Scheduling MajorDeltaCompactionOp(fa0626524a414e1fb9312a4008f2ea05): perf score=1.000000
I20260812 06:17:15.155931 30461 maintenance_manager.cc:643] P 0414c4f10eb24d4badaf7b745880c39a: MajorDeltaCompactionOp(fa0626524a414e1fb9312a4008f2ea05) complete. Timing: real 0.157s	user 0.091s	sys 0.066s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":137,"lbm_read_time_us":12502,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25235,"lbm_writes_lt_1ms":443,"mutex_wait_us":25,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":15616,"update_count":2000}
I20260812 06:17:15.160053 30530 maintenance_manager.cc:419] P 0414c4f10eb24d4badaf7b745880c39a: Scheduling FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05): perf score=11.118625
I20260812 06:17:15.195962 30461 maintenance_manager.cc:643] P 0414c4f10eb24d4badaf7b745880c39a: FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05) complete. Timing: real 0.035s	user 0.020s	sys 0.012s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":14780,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:15.196637 30530 maintenance_manager.cc:419] P 0414c4f10eb24d4badaf7b745880c39a: Scheduling FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05): perf score=2.188937
I20260812 06:17:15.213907 30461 maintenance_manager.cc:643] P 0414c4f10eb24d4badaf7b745880c39a: FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05) complete. Timing: real 0.017s	user 0.011s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5668,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:15.214493 30530 maintenance_manager.cc:419] P 0414c4f10eb24d4badaf7b745880c39a: Scheduling MajorDeltaCompactionOp(fa0626524a414e1fb9312a4008f2ea05): perf score=1.000000
I20260812 06:17:15.338804 30461 maintenance_manager.cc:643] P 0414c4f10eb24d4badaf7b745880c39a: MajorDeltaCompactionOp(fa0626524a414e1fb9312a4008f2ea05) complete. Timing: real 0.124s	user 0.112s	sys 0.012s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631303,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":380,"lbm_read_time_us":7629,"lbm_reads_lt_1ms":464,"lbm_write_time_us":25977,"lbm_writes_lt_1ms":443,"mutex_wait_us":22,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11648,"update_count":2000}
I20260812 06:17:15.339408 30530 maintenance_manager.cc:419] P 0414c4f10eb24d4badaf7b745880c39a: Scheduling FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05): perf score=10.126437
I20260812 06:17:15.373871 30461 maintenance_manager.cc:643] P 0414c4f10eb24d4badaf7b745880c39a: FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05) complete. Timing: real 0.034s	user 0.031s	sys 0.003s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14751,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:15.374497 30530 maintenance_manager.cc:419] P 0414c4f10eb24d4badaf7b745880c39a: Scheduling FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05): perf score=2.188937
I20260812 06:17:15.390465 30461 maintenance_manager.cc:643] P 0414c4f10eb24d4badaf7b745880c39a: FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05) complete. Timing: real 0.016s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5993,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:15.391278 30530 maintenance_manager.cc:419] P 0414c4f10eb24d4badaf7b745880c39a: Scheduling FlushMRSOp(fa0626524a414e1fb9312a4008f2ea05): perf score=1.000000
I20260812 06:17:15.421952 30461 maintenance_manager.cc:643] P 0414c4f10eb24d4badaf7b745880c39a: FlushMRSOp(fa0626524a414e1fb9312a4008f2ea05) complete. Timing: real 0.030s	user 0.030s	sys 0.000s Metrics: {"bytes_written":1234479,"cfile_init":1,"dirs.queue_time_us":57,"dirs.run_cpu_time_us":188,"dirs.run_wall_time_us":1444,"drs_written":1,"lbm_read_time_us":60,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2027,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:17:15.422780 30530 maintenance_manager.cc:419] P 0414c4f10eb24d4badaf7b745880c39a: Scheduling LogGCOp(fa0626524a414e1fb9312a4008f2ea05): free 128867395 bytes of WAL
I20260812 06:17:15.423069 30461 log_reader.cc:385] T fa0626524a414e1fb9312a4008f2ea05: removed 13 log segments from log reader
I20260812 06:17:15.423131 30461 log.cc:1079] T fa0626524a414e1fb9312a4008f2ea05 P 0414c4f10eb24d4badaf7b745880c39a: Deleting log segment in path: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431940255-30341-0/minicluster-data/ts-0-root/wals/fa0626524a414e1fb9312a4008f2ea05/wal-000000014 (ops 66-70)
I20260812 06:17:15.423173 30461 log.cc:1079] T fa0626524a414e1fb9312a4008f2ea05 P 0414c4f10eb24d4badaf7b745880c39a: Deleting log segment in path: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431940255-30341-0/minicluster-data/ts-0-root/wals/fa0626524a414e1fb9312a4008f2ea05/wal-000000015 (ops 71-75)
I20260812 06:17:15.423208 30461 log.cc:1079] T fa0626524a414e1fb9312a4008f2ea05 P 0414c4f10eb24d4badaf7b745880c39a: Deleting log segment in path: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431940255-30341-0/minicluster-data/ts-0-root/wals/fa0626524a414e1fb9312a4008f2ea05/wal-000000016 (ops 76-80)
I20260812 06:17:15.423241 30461 log.cc:1079] T fa0626524a414e1fb9312a4008f2ea05 P 0414c4f10eb24d4badaf7b745880c39a: Deleting log segment in path: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431940255-30341-0/minicluster-data/ts-0-root/wals/fa0626524a414e1fb9312a4008f2ea05/wal-000000017 (ops 81-84)
I20260812 06:17:15.423271 30461 log.cc:1079] T fa0626524a414e1fb9312a4008f2ea05 P 0414c4f10eb24d4badaf7b745880c39a: Deleting log segment in path: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431940255-30341-0/minicluster-data/ts-0-root/wals/fa0626524a414e1fb9312a4008f2ea05/wal-000000018 (ops 85-89)
I20260812 06:17:15.423293 30461 log.cc:1079] T fa0626524a414e1fb9312a4008f2ea05 P 0414c4f10eb24d4badaf7b745880c39a: Deleting log segment in path: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431940255-30341-0/minicluster-data/ts-0-root/wals/fa0626524a414e1fb9312a4008f2ea05/wal-000000019 (ops 90-94)
I20260812 06:17:15.423322 30461 log.cc:1079] T fa0626524a414e1fb9312a4008f2ea05 P 0414c4f10eb24d4badaf7b745880c39a: Deleting log segment in path: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431940255-30341-0/minicluster-data/ts-0-root/wals/fa0626524a414e1fb9312a4008f2ea05/wal-000000020 (ops 95-98)
I20260812 06:17:15.423357 30461 log.cc:1079] T fa0626524a414e1fb9312a4008f2ea05 P 0414c4f10eb24d4badaf7b745880c39a: Deleting log segment in path: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431940255-30341-0/minicluster-data/ts-0-root/wals/fa0626524a414e1fb9312a4008f2ea05/wal-000000021 (ops 99-103)
I20260812 06:17:15.423388 30461 log.cc:1079] T fa0626524a414e1fb9312a4008f2ea05 P 0414c4f10eb24d4badaf7b745880c39a: Deleting log segment in path: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431940255-30341-0/minicluster-data/ts-0-root/wals/fa0626524a414e1fb9312a4008f2ea05/wal-000000022 (ops 104-108)
I20260812 06:17:15.423415 30461 log.cc:1079] T fa0626524a414e1fb9312a4008f2ea05 P 0414c4f10eb24d4badaf7b745880c39a: Deleting log segment in path: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431940255-30341-0/minicluster-data/ts-0-root/wals/fa0626524a414e1fb9312a4008f2ea05/wal-000000023 (ops 109-113)
I20260812 06:17:15.423440 30461 log.cc:1079] T fa0626524a414e1fb9312a4008f2ea05 P 0414c4f10eb24d4badaf7b745880c39a: Deleting log segment in path: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431940255-30341-0/minicluster-data/ts-0-root/wals/fa0626524a414e1fb9312a4008f2ea05/wal-000000024 (ops 114-118)
I20260812 06:17:15.423465 30461 log.cc:1079] T fa0626524a414e1fb9312a4008f2ea05 P 0414c4f10eb24d4badaf7b745880c39a: Deleting log segment in path: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431940255-30341-0/minicluster-data/ts-0-root/wals/fa0626524a414e1fb9312a4008f2ea05/wal-000000025 (ops 119-122)
I20260812 06:17:15.423498 30461 log.cc:1079] T fa0626524a414e1fb9312a4008f2ea05 P 0414c4f10eb24d4badaf7b745880c39a: Deleting log segment in path: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431940255-30341-0/minicluster-data/ts-0-root/wals/fa0626524a414e1fb9312a4008f2ea05/wal-000000026 (ops 123-127)
I20260812 06:17:15.455031 30461 maintenance_manager.cc:643] P 0414c4f10eb24d4badaf7b745880c39a: LogGCOp(fa0626524a414e1fb9312a4008f2ea05) complete. Timing: real 0.032s	user 0.000s	sys 0.031s Metrics: {}
I20260812 06:17:15.455507 30530 maintenance_manager.cc:419] P 0414c4f10eb24d4badaf7b745880c39a: Scheduling FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05): perf score=2.188937
I20260812 06:17:15.477578 30461 maintenance_manager.cc:643] P 0414c4f10eb24d4badaf7b745880c39a: FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05) complete. Timing: real 0.022s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5944,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:15.478157 30530 maintenance_manager.cc:419] P 0414c4f10eb24d4badaf7b745880c39a: Scheduling FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05): perf score=2.188937
I20260812 06:17:15.489343 30461 maintenance_manager.cc:643] P 0414c4f10eb24d4badaf7b745880c39a: FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4269,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:15.489953 30530 maintenance_manager.cc:419] P 0414c4f10eb24d4badaf7b745880c39a: Scheduling MajorDeltaCompactionOp(fa0626524a414e1fb9312a4008f2ea05): perf score=1.000000
I20260812 06:17:15.678155 30461 maintenance_manager.cc:643] P 0414c4f10eb24d4badaf7b745880c39a: MajorDeltaCompactionOp(fa0626524a414e1fb9312a4008f2ea05) complete. Timing: real 0.188s	user 0.157s	sys 0.020s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836374,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":390,"lbm_read_time_us":13794,"lbm_reads_lt_1ms":674,"lbm_write_time_us":35652,"lbm_writes_lt_1ms":643,"mutex_wait_us":74,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":21376,"thread_start_us":95,"threads_started":1,"update_count":3000}
I20260812 06:17:15.679101 30530 maintenance_manager.cc:419] P 0414c4f10eb24d4badaf7b745880c39a: Scheduling UndoDeltaBlockGCOp(fa0626524a414e1fb9312a4008f2ea05): 472 bytes on disk
I20260812 06:17:15.679736 30461 maintenance_manager.cc:643] P 0414c4f10eb24d4badaf7b745880c39a: UndoDeltaBlockGCOp(fa0626524a414e1fb9312a4008f2ea05) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":97,"lbm_reads_lt_1ms":4}
I20260812 06:17:15.680595 30530 maintenance_manager.cc:419] P 0414c4f10eb24d4badaf7b745880c39a: Scheduling FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05): perf score=14.095187
I20260812 06:17:15.734565 30461 maintenance_manager.cc:643] P 0414c4f10eb24d4badaf7b745880c39a: FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05) complete. Timing: real 0.054s	user 0.035s	sys 0.012s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21559,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:15.735076 30530 maintenance_manager.cc:419] P 0414c4f10eb24d4badaf7b745880c39a: Scheduling FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05): perf score=2.188937
I20260812 06:17:15.747038 30461 maintenance_manager.cc:643] P 0414c4f10eb24d4badaf7b745880c39a: FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05) complete. Timing: real 0.012s	user 0.009s	sys 0.002s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4074,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:15.747614 30530 maintenance_manager.cc:419] P 0414c4f10eb24d4badaf7b745880c39a: Scheduling MajorDeltaCompactionOp(fa0626524a414e1fb9312a4008f2ea05): perf score=1.000000
I20260812 06:17:15.902571 30461 maintenance_manager.cc:643] P 0414c4f10eb24d4badaf7b745880c39a: MajorDeltaCompactionOp(fa0626524a414e1fb9312a4008f2ea05) complete. Timing: real 0.155s	user 0.107s	sys 0.047s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733724,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":844,"lbm_read_time_us":9822,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31838,"lbm_writes_lt_1ms":543,"mutex_wait_us":49,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5888,"update_count":2500}
I20260812 06:17:15.903163 30530 maintenance_manager.cc:419] P 0414c4f10eb24d4badaf7b745880c39a: Scheduling FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05): perf score=10.126437
I20260812 06:17:15.941864 30461 maintenance_manager.cc:643] P 0414c4f10eb24d4badaf7b745880c39a: FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05) complete. Timing: real 0.038s	user 0.013s	sys 0.025s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":17483,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:17:15.942584 30530 maintenance_manager.cc:419] P 0414c4f10eb24d4badaf7b745880c39a: Scheduling FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05): perf score=2.188937
I20260812 06:17:15.962445 30461 maintenance_manager.cc:643] P 0414c4f10eb24d4badaf7b745880c39a: FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05) complete. Timing: real 0.020s	user 0.008s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5955,"lbm_writes_lt_1ms":103,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":500}
I20260812 06:17:15.963116 30530 maintenance_manager.cc:419] P 0414c4f10eb24d4badaf7b745880c39a: Scheduling MajorDeltaCompactionOp(fa0626524a414e1fb9312a4008f2ea05): perf score=1.000000
I20260812 06:17:16.111689 30461 maintenance_manager.cc:643] P 0414c4f10eb24d4badaf7b745880c39a: MajorDeltaCompactionOp(fa0626524a414e1fb9312a4008f2ea05) complete. Timing: real 0.148s	user 0.104s	sys 0.044s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631313,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":368,"lbm_read_time_us":9700,"lbm_reads_lt_1ms":468,"lbm_write_time_us":24753,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":442,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:16.112532 30530 maintenance_manager.cc:419] P 0414c4f10eb24d4badaf7b745880c39a: Scheduling FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05): perf score=10.126437
I20260812 06:17:16.147153 30461 maintenance_manager.cc:643] P 0414c4f10eb24d4badaf7b745880c39a: FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05) complete. Timing: real 0.034s	user 0.021s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14998,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:16.147710 30530 maintenance_manager.cc:419] P 0414c4f10eb24d4badaf7b745880c39a: Scheduling FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05): perf score=2.188937
I20260812 06:17:16.167918 30461 maintenance_manager.cc:643] P 0414c4f10eb24d4badaf7b745880c39a: FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05) complete. Timing: real 0.020s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6360,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:16.168442 30530 maintenance_manager.cc:419] P 0414c4f10eb24d4badaf7b745880c39a: Scheduling MajorDeltaCompactionOp(fa0626524a414e1fb9312a4008f2ea05): perf score=1.000000
I20260812 06:17:16.352839 30461 maintenance_manager.cc:643] P 0414c4f10eb24d4badaf7b745880c39a: MajorDeltaCompactionOp(fa0626524a414e1fb9312a4008f2ea05) complete. Timing: real 0.184s	user 0.124s	sys 0.044s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631311,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":719,"lbm_read_time_us":10549,"lbm_reads_lt_1ms":464,"lbm_write_time_us":27857,"lbm_writes_lt_1ms":443,"mutex_wait_us":282,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7552,"update_count":2000}
I20260812 06:17:16.353564 30530 maintenance_manager.cc:419] P 0414c4f10eb24d4badaf7b745880c39a: Scheduling FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05): perf score=14.095187
I20260812 06:17:16.407943 30461 maintenance_manager.cc:643] P 0414c4f10eb24d4badaf7b745880c39a: FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05) complete. Timing: real 0.054s	user 0.036s	sys 0.011s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":22523,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:16.408479 30530 maintenance_manager.cc:419] P 0414c4f10eb24d4badaf7b745880c39a: Scheduling FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05): perf score=2.188937
I20260812 06:17:16.420177 30461 maintenance_manager.cc:643] P 0414c4f10eb24d4badaf7b745880c39a: FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4052,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:16.420696 30530 maintenance_manager.cc:419] P 0414c4f10eb24d4badaf7b745880c39a: Scheduling MajorDeltaCompactionOp(fa0626524a414e1fb9312a4008f2ea05): perf score=1.000000
I20260812 06:17:16.573527 30461 maintenance_manager.cc:643] P 0414c4f10eb24d4badaf7b745880c39a: MajorDeltaCompactionOp(fa0626524a414e1fb9312a4008f2ea05) complete. Timing: real 0.153s	user 0.115s	sys 0.037s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733722,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":280,"lbm_read_time_us":10736,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32694,"lbm_writes_lt_1ms":543,"mutex_wait_us":46,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":16128,"update_count":2500}
I20260812 06:17:16.574497 30530 maintenance_manager.cc:419] P 0414c4f10eb24d4badaf7b745880c39a: Scheduling FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05): perf score=11.118625
I20260812 06:17:16.609967 30461 maintenance_manager.cc:643] P 0414c4f10eb24d4badaf7b745880c39a: FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05) complete. Timing: real 0.035s	user 0.024s	sys 0.011s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15603,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:16.610533 30530 maintenance_manager.cc:419] P 0414c4f10eb24d4badaf7b745880c39a: Scheduling FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05): perf score=2.188937
I20260812 06:17:16.638715 30461 maintenance_manager.cc:643] P 0414c4f10eb24d4badaf7b745880c39a: FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05) complete. Timing: real 0.028s	user 0.013s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5238,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:16.639303 30530 maintenance_manager.cc:419] P 0414c4f10eb24d4badaf7b745880c39a: Scheduling FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05): perf score=2.188937
I20260812 06:17:16.650331 30461 maintenance_manager.cc:643] P 0414c4f10eb24d4badaf7b745880c39a: FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05) complete. Timing: real 0.011s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4242,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:16.650843 30530 maintenance_manager.cc:419] P 0414c4f10eb24d4badaf7b745880c39a: Scheduling MajorDeltaCompactionOp(fa0626524a414e1fb9312a4008f2ea05): perf score=1.000000
I20260812 06:17:16.827170 30461 maintenance_manager.cc:643] P 0414c4f10eb24d4badaf7b745880c39a: MajorDeltaCompactionOp(fa0626524a414e1fb9312a4008f2ea05) complete. Timing: real 0.176s	user 0.123s	sys 0.036s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24733834,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":806,"lbm_read_time_us":10934,"lbm_reads_lt_1ms":573,"lbm_write_time_us":34147,"lbm_writes_lt_1ms":543,"mutex_wait_us":110,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:17:16.827767 30530 maintenance_manager.cc:419] P 0414c4f10eb24d4badaf7b745880c39a: Scheduling FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05): perf score=14.095187
I20260812 06:17:16.891220 30461 maintenance_manager.cc:643] P 0414c4f10eb24d4badaf7b745880c39a: FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05) complete. Timing: real 0.063s	user 0.034s	sys 0.027s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":29297,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:17:16.891767 30530 maintenance_manager.cc:419] P 0414c4f10eb24d4badaf7b745880c39a: Scheduling FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05): perf score=2.188937
I20260812 06:17:16.905107 30461 maintenance_manager.cc:643] P 0414c4f10eb24d4badaf7b745880c39a: FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05) complete. Timing: real 0.013s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4589,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:16.905644 30530 maintenance_manager.cc:419] P 0414c4f10eb24d4badaf7b745880c39a: Scheduling FlushMRSOp(fa0626524a414e1fb9312a4008f2ea05): perf score=1.000000
I20260812 06:17:16.936043 30461 maintenance_manager.cc:643] P 0414c4f10eb24d4badaf7b745880c39a: FlushMRSOp(fa0626524a414e1fb9312a4008f2ea05) complete. Timing: real 0.030s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1234475,"cfile_init":1,"dirs.queue_time_us":94,"dirs.run_cpu_time_us":235,"dirs.run_wall_time_us":1294,"drs_written":1,"lbm_read_time_us":47,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1427,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:17:16.936767 30530 maintenance_manager.cc:419] P 0414c4f10eb24d4badaf7b745880c39a: Scheduling LogGCOp(fa0626524a414e1fb9312a4008f2ea05): free 124257554 bytes of WAL
I20260812 06:17:16.937022 30461 log_reader.cc:385] T fa0626524a414e1fb9312a4008f2ea05: removed 12 log segments from log reader
I20260812 06:17:16.937067 30461 log.cc:1079] T fa0626524a414e1fb9312a4008f2ea05 P 0414c4f10eb24d4badaf7b745880c39a: Deleting log segment in path: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431940255-30341-0/minicluster-data/ts-0-root/wals/fa0626524a414e1fb9312a4008f2ea05/wal-000000027 (ops 128-132)
I20260812 06:17:16.937104 30461 log.cc:1079] T fa0626524a414e1fb9312a4008f2ea05 P 0414c4f10eb24d4badaf7b745880c39a: Deleting log segment in path: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431940255-30341-0/minicluster-data/ts-0-root/wals/fa0626524a414e1fb9312a4008f2ea05/wal-000000028 (ops 133-137)
I20260812 06:17:16.937162 30461 log.cc:1079] T fa0626524a414e1fb9312a4008f2ea05 P 0414c4f10eb24d4badaf7b745880c39a: Deleting log segment in path: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431940255-30341-0/minicluster-data/ts-0-root/wals/fa0626524a414e1fb9312a4008f2ea05/wal-000000029 (ops 138-142)
I20260812 06:17:16.937208 30461 log.cc:1079] T fa0626524a414e1fb9312a4008f2ea05 P 0414c4f10eb24d4badaf7b745880c39a: Deleting log segment in path: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431940255-30341-0/minicluster-data/ts-0-root/wals/fa0626524a414e1fb9312a4008f2ea05/wal-000000030 (ops 143-147)
I20260812 06:17:16.937228 30461 log.cc:1079] T fa0626524a414e1fb9312a4008f2ea05 P 0414c4f10eb24d4badaf7b745880c39a: Deleting log segment in path: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431940255-30341-0/minicluster-data/ts-0-root/wals/fa0626524a414e1fb9312a4008f2ea05/wal-000000031 (ops 148-152)
I20260812 06:17:16.937288 30461 log.cc:1079] T fa0626524a414e1fb9312a4008f2ea05 P 0414c4f10eb24d4badaf7b745880c39a: Deleting log segment in path: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431940255-30341-0/minicluster-data/ts-0-root/wals/fa0626524a414e1fb9312a4008f2ea05/wal-000000032 (ops 153-156)
I20260812 06:17:16.937327 30461 log.cc:1079] T fa0626524a414e1fb9312a4008f2ea05 P 0414c4f10eb24d4badaf7b745880c39a: Deleting log segment in path: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431940255-30341-0/minicluster-data/ts-0-root/wals/fa0626524a414e1fb9312a4008f2ea05/wal-000000033 (ops 157-161)
I20260812 06:17:16.937384 30461 log.cc:1079] T fa0626524a414e1fb9312a4008f2ea05 P 0414c4f10eb24d4badaf7b745880c39a: Deleting log segment in path: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431940255-30341-0/minicluster-data/ts-0-root/wals/fa0626524a414e1fb9312a4008f2ea05/wal-000000034 (ops 162-166)
I20260812 06:17:16.937425 30461 log.cc:1079] T fa0626524a414e1fb9312a4008f2ea05 P 0414c4f10eb24d4badaf7b745880c39a: Deleting log segment in path: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431940255-30341-0/minicluster-data/ts-0-root/wals/fa0626524a414e1fb9312a4008f2ea05/wal-000000035 (ops 167-171)
I20260812 06:17:16.937455 30461 log.cc:1079] T fa0626524a414e1fb9312a4008f2ea05 P 0414c4f10eb24d4badaf7b745880c39a: Deleting log segment in path: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431940255-30341-0/minicluster-data/ts-0-root/wals/fa0626524a414e1fb9312a4008f2ea05/wal-000000036 (ops 172-176)
I20260812 06:17:16.937491 30461 log.cc:1079] T fa0626524a414e1fb9312a4008f2ea05 P 0414c4f10eb24d4badaf7b745880c39a: Deleting log segment in path: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431940255-30341-0/minicluster-data/ts-0-root/wals/fa0626524a414e1fb9312a4008f2ea05/wal-000000037 (ops 177-181)
I20260812 06:17:16.937522 30461 log.cc:1079] T fa0626524a414e1fb9312a4008f2ea05 P 0414c4f10eb24d4badaf7b745880c39a: Deleting log segment in path: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431940255-30341-0/minicluster-data/ts-0-root/wals/fa0626524a414e1fb9312a4008f2ea05/wal-000000038 (ops 182-186)
I20260812 06:17:16.966493 30461 maintenance_manager.cc:643] P 0414c4f10eb24d4badaf7b745880c39a: LogGCOp(fa0626524a414e1fb9312a4008f2ea05) complete. Timing: real 0.030s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:17:16.967291 30530 maintenance_manager.cc:419] P 0414c4f10eb24d4badaf7b745880c39a: Scheduling UndoDeltaBlockGCOp(fa0626524a414e1fb9312a4008f2ea05): 472 bytes on disk
I20260812 06:17:16.968170 30461 maintenance_manager.cc:643] P 0414c4f10eb24d4badaf7b745880c39a: UndoDeltaBlockGCOp(fa0626524a414e1fb9312a4008f2ea05) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":59,"lbm_reads_lt_1ms":4}
I20260812 06:17:16.968770 30530 maintenance_manager.cc:419] P 0414c4f10eb24d4badaf7b745880c39a: Scheduling FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05): perf score=6.157687
I20260812 06:17:16.990391 30461 maintenance_manager.cc:643] P 0414c4f10eb24d4badaf7b745880c39a: FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05) complete. Timing: real 0.021s	user 0.012s	sys 0.009s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":9026,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:17:16.990926 30530 maintenance_manager.cc:419] P 0414c4f10eb24d4badaf7b745880c39a: Scheduling MajorDeltaCompactionOp(fa0626524a414e1fb9312a4008f2ea05): perf score=1.000000
I20260812 06:17:17.428819 30461 maintenance_manager.cc:643] P 0414c4f10eb24d4badaf7b745880c39a: MajorDeltaCompactionOp(fa0626524a414e1fb9312a4008f2ea05) complete. Timing: real 0.438s	user 0.282s	sys 0.104s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":32938667,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":2863,"lbm_read_time_us":17794,"lbm_reads_lt_1ms":769,"lbm_write_time_us":76455,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":32128,"thread_start_us":1668,"threads_started":6,"update_count":3500}
I20260812 06:17:17.431744 30530 maintenance_manager.cc:419] P 0414c4f10eb24d4badaf7b745880c39a: Scheduling FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05): perf score=18.063937
I20260812 06:17:17.536222 30341 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.265s	user 1.949s	sys 0.146s
I20260812 06:17:17.607483 30341 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.069s	user 0.006s	sys 0.000s
I20260812 06:17:17.608551 30341 tablet_server.cc:179] TabletServer@127.29.161.65:0 shutting down...
I20260812 06:17:17.608531 30461 maintenance_manager.cc:643] P 0414c4f10eb24d4badaf7b745880c39a: FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05) complete. Timing: real 0.176s	user 0.105s	sys 0.060s Metrics: {"bytes_written":20512314,"delete_count":0,"lbm_write_time_us":82712,"lbm_writes_1-10_ms":4,"lbm_writes_lt_1ms":499,"reinsert_count":0,"update_count":2500}
I20260812 06:17:17.610075 30530 maintenance_manager.cc:419] P 0414c4f10eb24d4badaf7b745880c39a: Scheduling FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05): perf score=2.188937
I20260812 06:17:17.644630 30461 maintenance_manager.cc:643] P 0414c4f10eb24d4badaf7b745880c39a: FlushDeltaMemStoresOp(fa0626524a414e1fb9312a4008f2ea05) complete. Timing: real 0.034s	user 0.013s	sys 0.016s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":13272,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:17.646282 30341 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:17.647424 30341 tablet_replica.cc:333] T fa0626524a414e1fb9312a4008f2ea05 P 0414c4f10eb24d4badaf7b745880c39a: stopping tablet replica
I20260812 06:17:17.647861 30341 raft_consensus.cc:2243] T fa0626524a414e1fb9312a4008f2ea05 P 0414c4f10eb24d4badaf7b745880c39a [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:17.648391 30341 raft_consensus.cc:2272] T fa0626524a414e1fb9312a4008f2ea05 P 0414c4f10eb24d4badaf7b745880c39a [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:17.670948 30341 tablet_server.cc:196] TabletServer@127.29.161.65:0 shutdown complete.
I20260812 06:17:17.682126 30341 master.cc:562] Master@127.29.161.126:35119 shutting down...
I20260812 06:17:17.687674 30341 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 648895127e5c476bbc7fcef62b44ecb1 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:17.688064 30341 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 648895127e5c476bbc7fcef62b44ecb1 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:17.688231 30341 tablet_replica.cc:333] T 00000000000000000000000000000000 P 648895127e5c476bbc7fcef62b44ecb1: stopping tablet replica
I20260812 06:17:17.702416 30341 master.cc:584] Master@127.29.161.126:35119 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5882 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:17:17.834012 30341 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.29.161.126:42333
I20260812 06:17:17.834830 30341 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:17.838272 30570 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:17.838455 30573 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:17.838384 30341 server_base.cc:1061] running on GCE node
W20260812 06:17:17.838284 30571 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:17.838955 30341 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:17.839097 30341 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:17.839151 30341 hybrid_clock.cc:648] HybridClock initialized: now 1786515437839150 us; error 0 us; skew 500 ppm
I20260812 06:17:17.840389 30341 webserver.cc:533] Webserver started at http://127.29.161.126:34291/ using document root <none> and password file <none>
I20260812 06:17:17.840657 30341 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:17.840819 30341 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:17.840955 30341 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:17.841629 30341 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431940255-30341-0/minicluster-data/master-0-root/instance:
uuid: "1be2e7b1650c498ba330a919d34c9200"
format_stamp: "Formatted at 2026-08-12 06:17:17 on dist-test-slave-0kls"
I20260812 06:17:17.844667 30341 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.000s	sys 0.002s
I20260812 06:17:17.846339 30578 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:17.846767 30341 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:17.846864 30341 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431940255-30341-0/minicluster-data/master-0-root
uuid: "1be2e7b1650c498ba330a919d34c9200"
format_stamp: "Formatted at 2026-08-12 06:17:17 on dist-test-slave-0kls"
I20260812 06:17:17.846985 30341 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431940255-30341-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431940255-30341-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431940255-30341-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:17.887238 30341 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:17.888264 30341 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:17.897377 30341 rpc_server.cc:307] RPC server started. Bound to: 127.29.161.126:42333
I20260812 06:17:17.899179 30635 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.29.161.126:42333 every 8 connection(s)
I20260812 06:17:17.902753 30636 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:17.922839 30636 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 1be2e7b1650c498ba330a919d34c9200: Bootstrap starting.
I20260812 06:17:17.924542 30636 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 1be2e7b1650c498ba330a919d34c9200: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:17.926647 30636 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 1be2e7b1650c498ba330a919d34c9200: No bootstrap required, opened a new log
I20260812 06:17:17.927515 30636 raft_consensus.cc:359] T 00000000000000000000000000000000 P 1be2e7b1650c498ba330a919d34c9200 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1be2e7b1650c498ba330a919d34c9200" member_type: VOTER }
I20260812 06:17:17.927711 30636 raft_consensus.cc:385] T 00000000000000000000000000000000 P 1be2e7b1650c498ba330a919d34c9200 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:17.927845 30636 raft_consensus.cc:740] T 00000000000000000000000000000000 P 1be2e7b1650c498ba330a919d34c9200 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 1be2e7b1650c498ba330a919d34c9200, State: Initialized, Role: FOLLOWER
I20260812 06:17:17.928143 30636 consensus_queue.cc:260] T 00000000000000000000000000000000 P 1be2e7b1650c498ba330a919d34c9200 [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: "1be2e7b1650c498ba330a919d34c9200" member_type: VOTER }
I20260812 06:17:17.928308 30636 raft_consensus.cc:399] T 00000000000000000000000000000000 P 1be2e7b1650c498ba330a919d34c9200 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:17.928443 30636 raft_consensus.cc:493] T 00000000000000000000000000000000 P 1be2e7b1650c498ba330a919d34c9200 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:17.928581 30636 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 1be2e7b1650c498ba330a919d34c9200 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:17.930074 30636 raft_consensus.cc:515] T 00000000000000000000000000000000 P 1be2e7b1650c498ba330a919d34c9200 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1be2e7b1650c498ba330a919d34c9200" member_type: VOTER }
I20260812 06:17:17.930332 30636 leader_election.cc:304] T 00000000000000000000000000000000 P 1be2e7b1650c498ba330a919d34c9200 [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: 1be2e7b1650c498ba330a919d34c9200; no voters: 
I20260812 06:17:17.930706 30636 leader_election.cc:290] T 00000000000000000000000000000000 P 1be2e7b1650c498ba330a919d34c9200 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:17.931072 30639 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 1be2e7b1650c498ba330a919d34c9200 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:17.931489 30639 raft_consensus.cc:697] T 00000000000000000000000000000000 P 1be2e7b1650c498ba330a919d34c9200 [term 1 LEADER]: Becoming Leader. State: Replica: 1be2e7b1650c498ba330a919d34c9200, State: Running, Role: LEADER
I20260812 06:17:17.931609 30636 sys_catalog.cc:565] T 00000000000000000000000000000000 P 1be2e7b1650c498ba330a919d34c9200 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:17.931794 30639 consensus_queue.cc:237] T 00000000000000000000000000000000 P 1be2e7b1650c498ba330a919d34c9200 [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: "1be2e7b1650c498ba330a919d34c9200" member_type: VOTER }
I20260812 06:17:17.933009 30641 sys_catalog.cc:455] T 00000000000000000000000000000000 P 1be2e7b1650c498ba330a919d34c9200 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "1be2e7b1650c498ba330a919d34c9200" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1be2e7b1650c498ba330a919d34c9200" member_type: VOTER } }
I20260812 06:17:17.933179 30641 sys_catalog.cc:458] T 00000000000000000000000000000000 P 1be2e7b1650c498ba330a919d34c9200 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:17.933065 30642 sys_catalog.cc:455] T 00000000000000000000000000000000 P 1be2e7b1650c498ba330a919d34c9200 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 1be2e7b1650c498ba330a919d34c9200. Latest consensus state: current_term: 1 leader_uuid: "1be2e7b1650c498ba330a919d34c9200" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1be2e7b1650c498ba330a919d34c9200" member_type: VOTER } }
I20260812 06:17:17.933264 30642 sys_catalog.cc:458] T 00000000000000000000000000000000 P 1be2e7b1650c498ba330a919d34c9200 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:17.933765 30649 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:17.935763 30649 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:17.936148 30341 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:17.939405 30649 catalog_manager.cc:1383] Generated new cluster ID: 53a8bf0232864f659e71b8596cef604e
I20260812 06:17:17.939535 30649 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:17.966293 30649 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:17.967772 30649 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:17.975876 30649 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 1be2e7b1650c498ba330a919d34c9200: Generated new TSK 0
I20260812 06:17:17.976315 30649 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:18.001948 30341 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:18.006420 30660 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:18.006575 30341 server_base.cc:1061] running on GCE node
W20260812 06:17:18.006790 30663 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:18.006951 30661 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:18.007416 30341 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:18.007521 30341 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:18.007570 30341 hybrid_clock.cc:648] HybridClock initialized: now 1786515438007569 us; error 0 us; skew 500 ppm
I20260812 06:17:18.009267 30341 webserver.cc:533] Webserver started at http://127.29.161.65:46543/ using document root <none> and password file <none>
I20260812 06:17:18.009572 30341 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:18.009759 30341 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:18.009958 30341 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:18.010685 30341 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431940255-30341-0/minicluster-data/ts-0-root/instance:
uuid: "fd53452bc3094c70bc576aac396a4ddc"
format_stamp: "Formatted at 2026-08-12 06:17:18 on dist-test-slave-0kls"
I20260812 06:17:18.014514 30341 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.000s	sys 0.004s
I20260812 06:17:18.016490 30669 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:18.017158 30341 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:18.017328 30341 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431940255-30341-0/minicluster-data/ts-0-root
uuid: "fd53452bc3094c70bc576aac396a4ddc"
format_stamp: "Formatted at 2026-08-12 06:17:18 on dist-test-slave-0kls"
I20260812 06:17:18.017508 30341 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431940255-30341-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431940255-30341-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431940255-30341-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:18.045032 30341 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:18.045666 30341 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:18.046391 30341 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:18.047302 30341 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:18.047374 30341 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:18.047479 30341 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:18.047571 30341 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:18.056878 30341 rpc_server.cc:307] RPC server started. Bound to: 127.29.161.65:34317
I20260812 06:17:18.056893 30740 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.29.161.65:34317 every 8 connection(s)
I20260812 06:17:18.065322 30741 heartbeater.cc:344] Connected to a master server at 127.29.161.126:42333
I20260812 06:17:18.065606 30741 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:18.066140 30741 heartbeater.cc:507] Master 127.29.161.126:42333 requested a full tablet report, sending...
I20260812 06:17:18.067494 30598 ts_manager.cc:194] Registered new tserver with Master: fd53452bc3094c70bc576aac396a4ddc (127.29.161.65:34317)
I20260812 06:17:18.067842 30341 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.010201739s
I20260812 06:17:18.068760 30598 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:36626
I20260812 06:17:18.082362 30598 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:36640:
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:18.100986 30699 tablet_service.cc:1511] Processing CreateTablet for tablet 1b6ad3af72e843869bcb40021fbb0eca (DEFAULT_TABLE table=heavy-update-compaction-test [id=c10c99eb41104c948259080a028f86be]), partition=
I20260812 06:17:18.101507 30699 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 1b6ad3af72e843869bcb40021fbb0eca. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:18.106038 30756 tablet_bootstrap.cc:492] T 1b6ad3af72e843869bcb40021fbb0eca P fd53452bc3094c70bc576aac396a4ddc: Bootstrap starting.
I20260812 06:17:18.107779 30756 tablet_bootstrap.cc:654] T 1b6ad3af72e843869bcb40021fbb0eca P fd53452bc3094c70bc576aac396a4ddc: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:18.110040 30756 tablet_bootstrap.cc:492] T 1b6ad3af72e843869bcb40021fbb0eca P fd53452bc3094c70bc576aac396a4ddc: No bootstrap required, opened a new log
I20260812 06:17:18.110275 30756 ts_tablet_manager.cc:1403] T 1b6ad3af72e843869bcb40021fbb0eca P fd53452bc3094c70bc576aac396a4ddc: Time spent bootstrapping tablet: real 0.004s	user 0.004s	sys 0.000s
I20260812 06:17:18.111080 30756 raft_consensus.cc:359] T 1b6ad3af72e843869bcb40021fbb0eca P fd53452bc3094c70bc576aac396a4ddc [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "fd53452bc3094c70bc576aac396a4ddc" member_type: VOTER last_known_addr { host: "127.29.161.65" port: 34317 } }
I20260812 06:17:18.111279 30756 raft_consensus.cc:385] T 1b6ad3af72e843869bcb40021fbb0eca P fd53452bc3094c70bc576aac396a4ddc [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:18.111405 30756 raft_consensus.cc:740] T 1b6ad3af72e843869bcb40021fbb0eca P fd53452bc3094c70bc576aac396a4ddc [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: fd53452bc3094c70bc576aac396a4ddc, State: Initialized, Role: FOLLOWER
I20260812 06:17:18.111774 30756 consensus_queue.cc:260] T 1b6ad3af72e843869bcb40021fbb0eca P fd53452bc3094c70bc576aac396a4ddc [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: "fd53452bc3094c70bc576aac396a4ddc" member_type: VOTER last_known_addr { host: "127.29.161.65" port: 34317 } }
I20260812 06:17:18.111960 30756 raft_consensus.cc:399] T 1b6ad3af72e843869bcb40021fbb0eca P fd53452bc3094c70bc576aac396a4ddc [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:18.112066 30756 raft_consensus.cc:493] T 1b6ad3af72e843869bcb40021fbb0eca P fd53452bc3094c70bc576aac396a4ddc [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:18.112181 30756 raft_consensus.cc:3060] T 1b6ad3af72e843869bcb40021fbb0eca P fd53452bc3094c70bc576aac396a4ddc [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:18.113664 30756 raft_consensus.cc:515] T 1b6ad3af72e843869bcb40021fbb0eca P fd53452bc3094c70bc576aac396a4ddc [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "fd53452bc3094c70bc576aac396a4ddc" member_type: VOTER last_known_addr { host: "127.29.161.65" port: 34317 } }
I20260812 06:17:18.114002 30756 leader_election.cc:304] T 1b6ad3af72e843869bcb40021fbb0eca P fd53452bc3094c70bc576aac396a4ddc [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: fd53452bc3094c70bc576aac396a4ddc; no voters: 
I20260812 06:17:18.114400 30756 leader_election.cc:290] T 1b6ad3af72e843869bcb40021fbb0eca P fd53452bc3094c70bc576aac396a4ddc [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:18.114825 30758 raft_consensus.cc:2804] T 1b6ad3af72e843869bcb40021fbb0eca P fd53452bc3094c70bc576aac396a4ddc [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:18.115216 30756 ts_tablet_manager.cc:1434] T 1b6ad3af72e843869bcb40021fbb0eca P fd53452bc3094c70bc576aac396a4ddc: Time spent starting tablet: real 0.005s	user 0.005s	sys 0.000s
I20260812 06:17:18.115269 30741 heartbeater.cc:499] Master 127.29.161.126:42333 was elected leader, sending a full tablet report...
I20260812 06:17:18.115386 30758 raft_consensus.cc:697] T 1b6ad3af72e843869bcb40021fbb0eca P fd53452bc3094c70bc576aac396a4ddc [term 1 LEADER]: Becoming Leader. State: Replica: fd53452bc3094c70bc576aac396a4ddc, State: Running, Role: LEADER
I20260812 06:17:18.115757 30758 consensus_queue.cc:237] T 1b6ad3af72e843869bcb40021fbb0eca P fd53452bc3094c70bc576aac396a4ddc [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: "fd53452bc3094c70bc576aac396a4ddc" member_type: VOTER last_known_addr { host: "127.29.161.65" port: 34317 } }
I20260812 06:17:18.118979 30598 catalog_manager.cc:5719] T 1b6ad3af72e843869bcb40021fbb0eca P fd53452bc3094c70bc576aac396a4ddc reported cstate change: term changed from 0 to 1, leader changed from <none> to fd53452bc3094c70bc576aac396a4ddc (127.29.161.65). New cstate: current_term: 1 leader_uuid: "fd53452bc3094c70bc576aac396a4ddc" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "fd53452bc3094c70bc576aac396a4ddc" member_type: VOTER last_known_addr { host: "127.29.161.65" port: 34317 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:18.220366 30341 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.095s	user 0.028s	sys 0.012s
I20260812 06:17:18.308548 30742 maintenance_manager.cc:419] P fd53452bc3094c70bc576aac396a4ddc: Scheduling FlushMRSOp(1b6ad3af72e843869bcb40021fbb0eca): perf score=6.156503
I20260812 06:17:18.529366 30675 maintenance_manager.cc:643] P fd53452bc3094c70bc576aac396a4ddc: FlushMRSOp(1b6ad3af72e843869bcb40021fbb0eca) complete. Timing: real 0.220s	user 0.130s	sys 0.071s Metrics: {"bytes_written":8205078,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":144,"dirs.run_cpu_time_us":326,"dirs.run_wall_time_us":1112,"drs_written":1,"lbm_read_time_us":86,"lbm_reads_lt_1ms":4,"lbm_write_time_us":47135,"lbm_writes_lt_1ms":357,"peak_mem_usage":0,"reinsert_count":0,"rows_written":101,"update_count":1000}
I20260812 06:17:18.530977 30742 maintenance_manager.cc:419] P fd53452bc3094c70bc576aac396a4ddc: Scheduling UndoDeltaBlockGCOp(1b6ad3af72e843869bcb40021fbb0eca): 4103815 bytes on disk
I20260812 06:17:18.532014 30675 maintenance_manager.cc:643] P fd53452bc3094c70bc576aac396a4ddc: UndoDeltaBlockGCOp(1b6ad3af72e843869bcb40021fbb0eca) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":140,"lbm_reads_lt_1ms":4}
I20260812 06:17:18.533278 30742 maintenance_manager.cc:419] P fd53452bc3094c70bc576aac396a4ddc: Scheduling FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca): perf score=2.188937
I20260812 06:17:18.566294 30675 maintenance_manager.cc:643] P fd53452bc3094c70bc576aac396a4ddc: FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca) complete. Timing: real 0.032s	user 0.021s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":13011,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:18.567376 30742 maintenance_manager.cc:419] P fd53452bc3094c70bc576aac396a4ddc: Scheduling MajorDeltaCompactionOp(1b6ad3af72e843869bcb40021fbb0eca): perf score=1.000000
I20260812 06:17:18.784354 30675 maintenance_manager.cc:643] P fd53452bc3094c70bc576aac396a4ddc: MajorDeltaCompactionOp(1b6ad3af72e843869bcb40021fbb0eca) complete. Timing: real 0.217s	user 0.160s	sys 0.048s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16446970,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1104,"lbm_read_time_us":16990,"lbm_reads_lt_1ms":364,"lbm_write_time_us":35490,"lbm_writes_lt_1ms":343,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":1408,"thread_start_us":596,"threads_started":5,"update_count":1500}
I20260812 06:17:18.785930 30742 maintenance_manager.cc:419] P fd53452bc3094c70bc576aac396a4ddc: Scheduling FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca): perf score=10.126437
I20260812 06:17:18.874147 30675 maintenance_manager.cc:643] P fd53452bc3094c70bc576aac396a4ddc: FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca) complete. Timing: real 0.088s	user 0.044s	sys 0.036s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":38402,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":300,"reinsert_count":0,"update_count":1500}
I20260812 06:17:18.874701 30742 maintenance_manager.cc:419] P fd53452bc3094c70bc576aac396a4ddc: Scheduling FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca): perf score=2.188937
I20260812 06:17:18.886930 30675 maintenance_manager.cc:643] P fd53452bc3094c70bc576aac396a4ddc: FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca) complete. Timing: real 0.012s	user 0.005s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4430,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:18.887446 30742 maintenance_manager.cc:419] P fd53452bc3094c70bc576aac396a4ddc: Scheduling MajorDeltaCompactionOp(1b6ad3af72e843869bcb40021fbb0eca): perf score=1.000000
I20260812 06:17:19.032150 30675 maintenance_manager.cc:643] P fd53452bc3094c70bc576aac396a4ddc: MajorDeltaCompactionOp(1b6ad3af72e843869bcb40021fbb0eca) complete. Timing: real 0.144s	user 0.117s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20549382,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":61,"lbm_read_time_us":8251,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24258,"lbm_writes_lt_1ms":443,"mutex_wait_us":35,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":25344,"update_count":2000}
I20260812 06:17:19.032912 30742 maintenance_manager.cc:419] P fd53452bc3094c70bc576aac396a4ddc: Scheduling FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca): perf score=10.126437
I20260812 06:17:19.073047 30675 maintenance_manager.cc:643] P fd53452bc3094c70bc576aac396a4ddc: FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca) complete. Timing: real 0.040s	user 0.004s	sys 0.033s Metrics: {"bytes_written":12307495,"delete_count":0,"lbm_write_time_us":17667,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:19.073624 30742 maintenance_manager.cc:419] P fd53452bc3094c70bc576aac396a4ddc: Scheduling FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca): perf score=2.188937
I20260812 06:17:19.085283 30675 maintenance_manager.cc:643] P fd53452bc3094c70bc576aac396a4ddc: FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4130,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:19.085866 30742 maintenance_manager.cc:419] P fd53452bc3094c70bc576aac396a4ddc: Scheduling MajorDeltaCompactionOp(1b6ad3af72e843869bcb40021fbb0eca): perf score=1.000000
I20260812 06:17:19.215687 30675 maintenance_manager.cc:643] P fd53452bc3094c70bc576aac396a4ddc: MajorDeltaCompactionOp(1b6ad3af72e843869bcb40021fbb0eca) complete. Timing: real 0.130s	user 0.108s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20549387,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":691,"lbm_read_time_us":9321,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23575,"lbm_writes_lt_1ms":443,"mutex_wait_us":48,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":15616,"update_count":2000}
I20260812 06:17:19.216534 30742 maintenance_manager.cc:419] P fd53452bc3094c70bc576aac396a4ddc: Scheduling FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca): perf score=10.126437
I20260812 06:17:19.254165 30675 maintenance_manager.cc:643] P fd53452bc3094c70bc576aac396a4ddc: FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca) complete. Timing: real 0.037s	user 0.021s	sys 0.015s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":16849,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:19.254740 30742 maintenance_manager.cc:419] P fd53452bc3094c70bc576aac396a4ddc: Scheduling FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca): perf score=2.188937
I20260812 06:17:19.270689 30675 maintenance_manager.cc:643] P fd53452bc3094c70bc576aac396a4ddc: FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca) complete. Timing: real 0.016s	user 0.015s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5936,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:19.271801 30742 maintenance_manager.cc:419] P fd53452bc3094c70bc576aac396a4ddc: Scheduling MajorDeltaCompactionOp(1b6ad3af72e843869bcb40021fbb0eca): perf score=1.000000
I20260812 06:17:19.400897 30675 maintenance_manager.cc:643] P fd53452bc3094c70bc576aac396a4ddc: MajorDeltaCompactionOp(1b6ad3af72e843869bcb40021fbb0eca) complete. Timing: real 0.129s	user 0.108s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20549381,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":241,"lbm_read_time_us":9074,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25127,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":27520,"update_count":2000}
I20260812 06:17:19.401832 30742 maintenance_manager.cc:419] P fd53452bc3094c70bc576aac396a4ddc: Scheduling FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca): perf score=10.126437
I20260812 06:17:19.453299 30675 maintenance_manager.cc:643] P fd53452bc3094c70bc576aac396a4ddc: FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca) complete. Timing: real 0.051s	user 0.028s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16520,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:19.454023 30742 maintenance_manager.cc:419] P fd53452bc3094c70bc576aac396a4ddc: Scheduling FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca): perf score=2.188937
I20260812 06:17:19.465341 30675 maintenance_manager.cc:643] P fd53452bc3094c70bc576aac396a4ddc: FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4392,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:19.466001 30742 maintenance_manager.cc:419] P fd53452bc3094c70bc576aac396a4ddc: Scheduling MajorDeltaCompactionOp(1b6ad3af72e843869bcb40021fbb0eca): perf score=1.000000
I20260812 06:17:19.617997 30675 maintenance_manager.cc:643] P fd53452bc3094c70bc576aac396a4ddc: MajorDeltaCompactionOp(1b6ad3af72e843869bcb40021fbb0eca) complete. Timing: real 0.152s	user 0.094s	sys 0.057s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20549382,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1016,"lbm_read_time_us":11427,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24853,"lbm_writes_lt_1ms":443,"mutex_wait_us":288,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:19.618906 30742 maintenance_manager.cc:419] P fd53452bc3094c70bc576aac396a4ddc: Scheduling FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca): perf score=10.126437
I20260812 06:17:19.658401 30675 maintenance_manager.cc:643] P fd53452bc3094c70bc576aac396a4ddc: FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca) complete. Timing: real 0.039s	user 0.036s	sys 0.000s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15463,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:19.659011 30742 maintenance_manager.cc:419] P fd53452bc3094c70bc576aac396a4ddc: Scheduling FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca): perf score=2.188937
I20260812 06:17:19.671200 30675 maintenance_manager.cc:643] P fd53452bc3094c70bc576aac396a4ddc: FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca) complete. Timing: real 0.012s	user 0.009s	sys 0.002s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4304,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:19.672026 30742 maintenance_manager.cc:419] P fd53452bc3094c70bc576aac396a4ddc: Scheduling MajorDeltaCompactionOp(1b6ad3af72e843869bcb40021fbb0eca): perf score=1.000000
I20260812 06:17:19.801371 30675 maintenance_manager.cc:643] P fd53452bc3094c70bc576aac396a4ddc: MajorDeltaCompactionOp(1b6ad3af72e843869bcb40021fbb0eca) complete. Timing: real 0.129s	user 0.112s	sys 0.017s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20549383,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":706,"lbm_read_time_us":10624,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23144,"lbm_writes_lt_1ms":443,"mutex_wait_us":20,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":15872,"update_count":2000}
I20260812 06:17:19.802129 30742 maintenance_manager.cc:419] P fd53452bc3094c70bc576aac396a4ddc: Scheduling FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca): perf score=10.126437
I20260812 06:17:19.845117 30675 maintenance_manager.cc:643] P fd53452bc3094c70bc576aac396a4ddc: FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca) complete. Timing: real 0.043s	user 0.026s	sys 0.011s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17340,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:19.845669 30742 maintenance_manager.cc:419] P fd53452bc3094c70bc576aac396a4ddc: Scheduling FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca): perf score=2.188937
I20260812 06:17:19.856941 30675 maintenance_manager.cc:643] P fd53452bc3094c70bc576aac396a4ddc: FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4148,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:19.857511 30742 maintenance_manager.cc:419] P fd53452bc3094c70bc576aac396a4ddc: Scheduling MajorDeltaCompactionOp(1b6ad3af72e843869bcb40021fbb0eca): perf score=1.000000
I20260812 06:17:19.990937 30675 maintenance_manager.cc:643] P fd53452bc3094c70bc576aac396a4ddc: MajorDeltaCompactionOp(1b6ad3af72e843869bcb40021fbb0eca) complete. Timing: real 0.133s	user 0.108s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20549383,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":229,"lbm_read_time_us":9981,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24134,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":28416,"update_count":2000}
I20260812 06:17:19.991523 30742 maintenance_manager.cc:419] P fd53452bc3094c70bc576aac396a4ddc: Scheduling FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca): perf score=10.126437
I20260812 06:17:20.042730 30675 maintenance_manager.cc:643] P fd53452bc3094c70bc576aac396a4ddc: FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca) complete. Timing: real 0.051s	user 0.028s	sys 0.012s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":18008,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:20.043257 30742 maintenance_manager.cc:419] P fd53452bc3094c70bc576aac396a4ddc: Scheduling FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca): perf score=2.188937
I20260812 06:17:20.059818 30675 maintenance_manager.cc:643] P fd53452bc3094c70bc576aac396a4ddc: FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca) complete. Timing: real 0.016s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6001,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:20.060563 30742 maintenance_manager.cc:419] P fd53452bc3094c70bc576aac396a4ddc: Scheduling FlushMRSOp(1b6ad3af72e843869bcb40021fbb0eca): perf score=1.000000
I20260812 06:17:20.094666 30675 maintenance_manager.cc:643] P fd53452bc3094c70bc576aac396a4ddc: FlushMRSOp(1b6ad3af72e843869bcb40021fbb0eca) complete. Timing: real 0.034s	user 0.028s	sys 0.005s Metrics: {"bytes_written":1275444,"cfile_init":1,"dirs.queue_time_us":82,"dirs.run_cpu_time_us":275,"dirs.run_wall_time_us":2146,"drs_written":1,"lbm_read_time_us":86,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1906,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:17:20.095281 30742 maintenance_manager.cc:419] P fd53452bc3094c70bc576aac396a4ddc: Scheduling LogGCOp(1b6ad3af72e843869bcb40021fbb0eca): free 132983155 bytes of WAL
I20260812 06:17:20.095530 30675 log_reader.cc:385] T 1b6ad3af72e843869bcb40021fbb0eca: removed 13 log segments from log reader
I20260812 06:17:20.095577 30675 log.cc:1079] T 1b6ad3af72e843869bcb40021fbb0eca P fd53452bc3094c70bc576aac396a4ddc: Deleting log segment in path: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431940255-30341-0/minicluster-data/ts-0-root/wals/1b6ad3af72e843869bcb40021fbb0eca/wal-000000001 (ops 1-6)
I20260812 06:17:20.095638 30675 log.cc:1079] T 1b6ad3af72e843869bcb40021fbb0eca P fd53452bc3094c70bc576aac396a4ddc: Deleting log segment in path: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431940255-30341-0/minicluster-data/ts-0-root/wals/1b6ad3af72e843869bcb40021fbb0eca/wal-000000002 (ops 7-11)
I20260812 06:17:20.095688 30675 log.cc:1079] T 1b6ad3af72e843869bcb40021fbb0eca P fd53452bc3094c70bc576aac396a4ddc: Deleting log segment in path: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431940255-30341-0/minicluster-data/ts-0-root/wals/1b6ad3af72e843869bcb40021fbb0eca/wal-000000003 (ops 12-16)
I20260812 06:17:20.095723 30675 log.cc:1079] T 1b6ad3af72e843869bcb40021fbb0eca P fd53452bc3094c70bc576aac396a4ddc: Deleting log segment in path: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431940255-30341-0/minicluster-data/ts-0-root/wals/1b6ad3af72e843869bcb40021fbb0eca/wal-000000004 (ops 17-21)
I20260812 06:17:20.095758 30675 log.cc:1079] T 1b6ad3af72e843869bcb40021fbb0eca P fd53452bc3094c70bc576aac396a4ddc: Deleting log segment in path: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431940255-30341-0/minicluster-data/ts-0-root/wals/1b6ad3af72e843869bcb40021fbb0eca/wal-000000005 (ops 22-26)
I20260812 06:17:20.095804 30675 log.cc:1079] T 1b6ad3af72e843869bcb40021fbb0eca P fd53452bc3094c70bc576aac396a4ddc: Deleting log segment in path: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431940255-30341-0/minicluster-data/ts-0-root/wals/1b6ad3af72e843869bcb40021fbb0eca/wal-000000006 (ops 27-31)
I20260812 06:17:20.095847 30675 log.cc:1079] T 1b6ad3af72e843869bcb40021fbb0eca P fd53452bc3094c70bc576aac396a4ddc: Deleting log segment in path: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431940255-30341-0/minicluster-data/ts-0-root/wals/1b6ad3af72e843869bcb40021fbb0eca/wal-000000007 (ops 32-36)
I20260812 06:17:20.095888 30675 log.cc:1079] T 1b6ad3af72e843869bcb40021fbb0eca P fd53452bc3094c70bc576aac396a4ddc: Deleting log segment in path: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431940255-30341-0/minicluster-data/ts-0-root/wals/1b6ad3af72e843869bcb40021fbb0eca/wal-000000008 (ops 37-41)
I20260812 06:17:20.095928 30675 log.cc:1079] T 1b6ad3af72e843869bcb40021fbb0eca P fd53452bc3094c70bc576aac396a4ddc: Deleting log segment in path: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431940255-30341-0/minicluster-data/ts-0-root/wals/1b6ad3af72e843869bcb40021fbb0eca/wal-000000009 (ops 42-46)
I20260812 06:17:20.095968 30675 log.cc:1079] T 1b6ad3af72e843869bcb40021fbb0eca P fd53452bc3094c70bc576aac396a4ddc: Deleting log segment in path: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431940255-30341-0/minicluster-data/ts-0-root/wals/1b6ad3af72e843869bcb40021fbb0eca/wal-000000010 (ops 47-51)
I20260812 06:17:20.096006 30675 log.cc:1079] T 1b6ad3af72e843869bcb40021fbb0eca P fd53452bc3094c70bc576aac396a4ddc: Deleting log segment in path: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431940255-30341-0/minicluster-data/ts-0-root/wals/1b6ad3af72e843869bcb40021fbb0eca/wal-000000011 (ops 52-56)
I20260812 06:17:20.096048 30675 log.cc:1079] T 1b6ad3af72e843869bcb40021fbb0eca P fd53452bc3094c70bc576aac396a4ddc: Deleting log segment in path: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431940255-30341-0/minicluster-data/ts-0-root/wals/1b6ad3af72e843869bcb40021fbb0eca/wal-000000012 (ops 57-60)
I20260812 06:17:20.096089 30675 log.cc:1079] T 1b6ad3af72e843869bcb40021fbb0eca P fd53452bc3094c70bc576aac396a4ddc: Deleting log segment in path: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431940255-30341-0/minicluster-data/ts-0-root/wals/1b6ad3af72e843869bcb40021fbb0eca/wal-000000013 (ops 61-65)
I20260812 06:17:20.125041 30675 maintenance_manager.cc:643] P fd53452bc3094c70bc576aac396a4ddc: LogGCOp(1b6ad3af72e843869bcb40021fbb0eca) complete. Timing: real 0.030s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:17:20.125627 30742 maintenance_manager.cc:419] P fd53452bc3094c70bc576aac396a4ddc: Scheduling UndoDeltaBlockGCOp(1b6ad3af72e843869bcb40021fbb0eca): 482 bytes on disk
I20260812 06:17:20.126150 30675 maintenance_manager.cc:643] P fd53452bc3094c70bc576aac396a4ddc: UndoDeltaBlockGCOp(1b6ad3af72e843869bcb40021fbb0eca) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4}
I20260812 06:17:20.126616 30742 maintenance_manager.cc:419] P fd53452bc3094c70bc576aac396a4ddc: Scheduling FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca): perf score=5.165500
I20260812 06:17:20.147979 30675 maintenance_manager.cc:643] P fd53452bc3094c70bc576aac396a4ddc: FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca) complete. Timing: real 0.021s	user 0.010s	sys 0.009s Metrics: {"bytes_written":6810258,"delete_count":0,"lbm_write_time_us":8839,"lbm_writes_lt_1ms":169,"reinsert_count":0,"update_count":830}
I20260812 06:17:20.148470 30742 maintenance_manager.cc:419] P fd53452bc3094c70bc576aac396a4ddc: Scheduling FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca): perf score=1.000000
I20260812 06:17:20.154660 30675 maintenance_manager.cc:643] P fd53452bc3094c70bc576aac396a4ddc: FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca) complete. Timing: real 0.006s	user 0.001s	sys 0.004s Metrics: {"bytes_written":1395002,"delete_count":0,"lbm_write_time_us":1629,"lbm_writes_lt_1ms":37,"reinsert_count":0,"update_count":170}
I20260812 06:17:20.155330 30742 maintenance_manager.cc:419] P fd53452bc3094c70bc576aac396a4ddc: Scheduling MajorDeltaCompactionOp(1b6ad3af72e843869bcb40021fbb0eca): perf score=1.000000
I20260812 06:17:20.327833 30675 maintenance_manager.cc:643] P fd53452bc3094c70bc576aac396a4ddc: MajorDeltaCompactionOp(1b6ad3af72e843869bcb40021fbb0eca) complete. Timing: real 0.172s	user 0.124s	sys 0.048s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28754379,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":804,"lbm_read_time_us":12450,"lbm_reads_lt_1ms":674,"lbm_write_time_us":34165,"lbm_writes_lt_1ms":643,"mutex_wait_us":129,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":7936,"thread_start_us":80,"threads_started":1,"update_count":3000}
I20260812 06:17:20.330657 30742 maintenance_manager.cc:419] P fd53452bc3094c70bc576aac396a4ddc: Scheduling FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca): perf score=14.095187
I20260812 06:17:20.386346 30675 maintenance_manager.cc:643] P fd53452bc3094c70bc576aac396a4ddc: FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca) complete. Timing: real 0.055s	user 0.019s	sys 0.032s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":23064,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:20.386916 30742 maintenance_manager.cc:419] P fd53452bc3094c70bc576aac396a4ddc: Scheduling FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca): perf score=2.188937
I20260812 06:17:20.403033 30675 maintenance_manager.cc:643] P fd53452bc3094c70bc576aac396a4ddc: FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca) complete. Timing: real 0.016s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5945,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:20.403602 30742 maintenance_manager.cc:419] P fd53452bc3094c70bc576aac396a4ddc: Scheduling MajorDeltaCompactionOp(1b6ad3af72e843869bcb40021fbb0eca): perf score=1.000000
I20260812 06:17:20.556638 30675 maintenance_manager.cc:643] P fd53452bc3094c70bc576aac396a4ddc: MajorDeltaCompactionOp(1b6ad3af72e843869bcb40021fbb0eca) complete. Timing: real 0.153s	user 0.109s	sys 0.043s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24651792,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":377,"lbm_read_time_us":11065,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28447,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4096,"update_count":2500}
I20260812 06:17:20.557331 30742 maintenance_manager.cc:419] P fd53452bc3094c70bc576aac396a4ddc: Scheduling FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca): perf score=10.126437
I20260812 06:17:20.592581 30675 maintenance_manager.cc:643] P fd53452bc3094c70bc576aac396a4ddc: FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca) complete. Timing: real 0.035s	user 0.031s	sys 0.000s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":14375,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:20.593281 30742 maintenance_manager.cc:419] P fd53452bc3094c70bc576aac396a4ddc: Scheduling FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca): perf score=2.188937
I20260812 06:17:20.608685 30675 maintenance_manager.cc:643] P fd53452bc3094c70bc576aac396a4ddc: FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca) complete. Timing: real 0.015s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5826,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:20.609380 30742 maintenance_manager.cc:419] P fd53452bc3094c70bc576aac396a4ddc: Scheduling MajorDeltaCompactionOp(1b6ad3af72e843869bcb40021fbb0eca): perf score=1.000000
I20260812 06:17:20.759451 30675 maintenance_manager.cc:643] P fd53452bc3094c70bc576aac396a4ddc: MajorDeltaCompactionOp(1b6ad3af72e843869bcb40021fbb0eca) complete. Timing: real 0.150s	user 0.120s	sys 0.030s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20549381,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":331,"lbm_read_time_us":10426,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24496,"lbm_writes_lt_1ms":443,"mutex_wait_us":43,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":19328,"update_count":2000}
I20260812 06:17:20.760246 30742 maintenance_manager.cc:419] P fd53452bc3094c70bc576aac396a4ddc: Scheduling FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca): perf score=10.126437
I20260812 06:17:20.801321 30675 maintenance_manager.cc:643] P fd53452bc3094c70bc576aac396a4ddc: FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca) complete. Timing: real 0.041s	user 0.016s	sys 0.017s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15704,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:20.801939 30742 maintenance_manager.cc:419] P fd53452bc3094c70bc576aac396a4ddc: Scheduling FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca): perf score=2.188937
I20260812 06:17:20.814235 30675 maintenance_manager.cc:643] P fd53452bc3094c70bc576aac396a4ddc: FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca) complete. Timing: real 0.012s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4299,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:20.815076 30742 maintenance_manager.cc:419] P fd53452bc3094c70bc576aac396a4ddc: Scheduling MajorDeltaCompactionOp(1b6ad3af72e843869bcb40021fbb0eca): perf score=1.000000
I20260812 06:17:20.963598 30675 maintenance_manager.cc:643] P fd53452bc3094c70bc576aac396a4ddc: MajorDeltaCompactionOp(1b6ad3af72e843869bcb40021fbb0eca) complete. Timing: real 0.148s	user 0.111s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20549381,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":304,"lbm_read_time_us":10704,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25582,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2432,"update_count":2000}
I20260812 06:17:20.964376 30742 maintenance_manager.cc:419] P fd53452bc3094c70bc576aac396a4ddc: Scheduling FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca): perf score=10.126437
I20260812 06:17:21.010288 30675 maintenance_manager.cc:643] P fd53452bc3094c70bc576aac396a4ddc: FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca) complete. Timing: real 0.046s	user 0.018s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14539,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:21.010830 30742 maintenance_manager.cc:419] P fd53452bc3094c70bc576aac396a4ddc: Scheduling FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca): perf score=2.188937
I20260812 06:17:21.021852 30675 maintenance_manager.cc:643] P fd53452bc3094c70bc576aac396a4ddc: FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4088,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:21.022737 30742 maintenance_manager.cc:419] P fd53452bc3094c70bc576aac396a4ddc: Scheduling MajorDeltaCompactionOp(1b6ad3af72e843869bcb40021fbb0eca): perf score=1.000000
I20260812 06:17:21.163506 30675 maintenance_manager.cc:643] P fd53452bc3094c70bc576aac396a4ddc: MajorDeltaCompactionOp(1b6ad3af72e843869bcb40021fbb0eca) complete. Timing: real 0.141s	user 0.108s	sys 0.030s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20549382,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":270,"lbm_read_time_us":9713,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28962,"lbm_writes_lt_1ms":443,"mutex_wait_us":22,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12288,"update_count":2000}
I20260812 06:17:21.164000 30742 maintenance_manager.cc:419] P fd53452bc3094c70bc576aac396a4ddc: Scheduling FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca): perf score=10.126437
I20260812 06:17:21.202744 30675 maintenance_manager.cc:643] P fd53452bc3094c70bc576aac396a4ddc: FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca) complete. Timing: real 0.039s	user 0.026s	sys 0.009s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":15163,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:21.203454 30742 maintenance_manager.cc:419] P fd53452bc3094c70bc576aac396a4ddc: Scheduling MajorDeltaCompactionOp(1b6ad3af72e843869bcb40021fbb0eca): perf score=1.000000
I20260812 06:17:21.315090 30675 maintenance_manager.cc:643] P fd53452bc3094c70bc576aac396a4ddc: MajorDeltaCompactionOp(1b6ad3af72e843869bcb40021fbb0eca) complete. Timing: real 0.111s	user 0.087s	sys 0.024s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16446854,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":395,"lbm_read_time_us":7478,"lbm_reads_lt_1ms":363,"lbm_write_time_us":21069,"lbm_writes_lt_1ms":343,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":1500}
I20260812 06:17:21.315904 30742 maintenance_manager.cc:419] P fd53452bc3094c70bc576aac396a4ddc: Scheduling FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca): perf score=10.126437
I20260812 06:17:21.354976 30675 maintenance_manager.cc:643] P fd53452bc3094c70bc576aac396a4ddc: FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca) complete. Timing: real 0.039s	user 0.025s	sys 0.009s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16178,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:21.355474 30742 maintenance_manager.cc:419] P fd53452bc3094c70bc576aac396a4ddc: Scheduling FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca): perf score=2.188937
I20260812 06:17:21.366353 30675 maintenance_manager.cc:643] P fd53452bc3094c70bc576aac396a4ddc: FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3941,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:21.367174 30742 maintenance_manager.cc:419] P fd53452bc3094c70bc576aac396a4ddc: Scheduling MajorDeltaCompactionOp(1b6ad3af72e843869bcb40021fbb0eca): perf score=1.000000
I20260812 06:17:21.505733 30675 maintenance_manager.cc:643] P fd53452bc3094c70bc576aac396a4ddc: MajorDeltaCompactionOp(1b6ad3af72e843869bcb40021fbb0eca) complete. Timing: real 0.138s	user 0.114s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20549381,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":268,"lbm_read_time_us":9080,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26907,"lbm_writes_lt_1ms":443,"mutex_wait_us":47,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4864,"update_count":2000}
I20260812 06:17:21.506492 30742 maintenance_manager.cc:419] P fd53452bc3094c70bc576aac396a4ddc: Scheduling FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca): perf score=10.126437
I20260812 06:17:21.555116 30675 maintenance_manager.cc:643] P fd53452bc3094c70bc576aac396a4ddc: FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca) complete. Timing: real 0.048s	user 0.031s	sys 0.007s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":17014,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:21.555624 30742 maintenance_manager.cc:419] P fd53452bc3094c70bc576aac396a4ddc: Scheduling FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca): perf score=2.188937
I20260812 06:17:21.566254 30675 maintenance_manager.cc:643] P fd53452bc3094c70bc576aac396a4ddc: FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3929,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:21.567044 30742 maintenance_manager.cc:419] P fd53452bc3094c70bc576aac396a4ddc: Scheduling FlushMRSOp(1b6ad3af72e843869bcb40021fbb0eca): perf score=1.000000
I20260812 06:17:21.596481 30675 maintenance_manager.cc:643] P fd53452bc3094c70bc576aac396a4ddc: FlushMRSOp(1b6ad3af72e843869bcb40021fbb0eca) complete. Timing: real 0.029s	user 0.026s	sys 0.000s Metrics: {"bytes_written":1234479,"cfile_init":1,"dirs.queue_time_us":95,"dirs.run_cpu_time_us":258,"dirs.run_wall_time_us":1418,"drs_written":1,"lbm_read_time_us":40,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1460,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:17:21.597240 30742 maintenance_manager.cc:419] P fd53452bc3094c70bc576aac396a4ddc: Scheduling LogGCOp(1b6ad3af72e843869bcb40021fbb0eca): free 120553389 bytes of WAL
I20260812 06:17:21.597512 30675 log_reader.cc:385] T 1b6ad3af72e843869bcb40021fbb0eca: removed 12 log segments from log reader
I20260812 06:17:21.597594 30675 log.cc:1079] T 1b6ad3af72e843869bcb40021fbb0eca P fd53452bc3094c70bc576aac396a4ddc: Deleting log segment in path: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431940255-30341-0/minicluster-data/ts-0-root/wals/1b6ad3af72e843869bcb40021fbb0eca/wal-000000014 (ops 66-70)
I20260812 06:17:21.597648 30675 log.cc:1079] T 1b6ad3af72e843869bcb40021fbb0eca P fd53452bc3094c70bc576aac396a4ddc: Deleting log segment in path: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431940255-30341-0/minicluster-data/ts-0-root/wals/1b6ad3af72e843869bcb40021fbb0eca/wal-000000015 (ops 71-75)
I20260812 06:17:21.597684 30675 log.cc:1079] T 1b6ad3af72e843869bcb40021fbb0eca P fd53452bc3094c70bc576aac396a4ddc: Deleting log segment in path: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431940255-30341-0/minicluster-data/ts-0-root/wals/1b6ad3af72e843869bcb40021fbb0eca/wal-000000016 (ops 76-80)
I20260812 06:17:21.597738 30675 log.cc:1079] T 1b6ad3af72e843869bcb40021fbb0eca P fd53452bc3094c70bc576aac396a4ddc: Deleting log segment in path: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431940255-30341-0/minicluster-data/ts-0-root/wals/1b6ad3af72e843869bcb40021fbb0eca/wal-000000017 (ops 81-84)
I20260812 06:17:21.597800 30675 log.cc:1079] T 1b6ad3af72e843869bcb40021fbb0eca P fd53452bc3094c70bc576aac396a4ddc: Deleting log segment in path: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431940255-30341-0/minicluster-data/ts-0-root/wals/1b6ad3af72e843869bcb40021fbb0eca/wal-000000018 (ops 85-89)
I20260812 06:17:21.597846 30675 log.cc:1079] T 1b6ad3af72e843869bcb40021fbb0eca P fd53452bc3094c70bc576aac396a4ddc: Deleting log segment in path: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431940255-30341-0/minicluster-data/ts-0-root/wals/1b6ad3af72e843869bcb40021fbb0eca/wal-000000019 (ops 90-94)
I20260812 06:17:21.597885 30675 log.cc:1079] T 1b6ad3af72e843869bcb40021fbb0eca P fd53452bc3094c70bc576aac396a4ddc: Deleting log segment in path: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431940255-30341-0/minicluster-data/ts-0-root/wals/1b6ad3af72e843869bcb40021fbb0eca/wal-000000020 (ops 95-99)
I20260812 06:17:21.597923 30675 log.cc:1079] T 1b6ad3af72e843869bcb40021fbb0eca P fd53452bc3094c70bc576aac396a4ddc: Deleting log segment in path: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431940255-30341-0/minicluster-data/ts-0-root/wals/1b6ad3af72e843869bcb40021fbb0eca/wal-000000021 (ops 100-104)
I20260812 06:17:21.597962 30675 log.cc:1079] T 1b6ad3af72e843869bcb40021fbb0eca P fd53452bc3094c70bc576aac396a4ddc: Deleting log segment in path: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431940255-30341-0/minicluster-data/ts-0-root/wals/1b6ad3af72e843869bcb40021fbb0eca/wal-000000022 (ops 105-109)
I20260812 06:17:21.597999 30675 log.cc:1079] T 1b6ad3af72e843869bcb40021fbb0eca P fd53452bc3094c70bc576aac396a4ddc: Deleting log segment in path: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431940255-30341-0/minicluster-data/ts-0-root/wals/1b6ad3af72e843869bcb40021fbb0eca/wal-000000023 (ops 110-114)
I20260812 06:17:21.598038 30675 log.cc:1079] T 1b6ad3af72e843869bcb40021fbb0eca P fd53452bc3094c70bc576aac396a4ddc: Deleting log segment in path: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431940255-30341-0/minicluster-data/ts-0-root/wals/1b6ad3af72e843869bcb40021fbb0eca/wal-000000024 (ops 115-118)
I20260812 06:17:21.598076 30675 log.cc:1079] T 1b6ad3af72e843869bcb40021fbb0eca P fd53452bc3094c70bc576aac396a4ddc: Deleting log segment in path: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431940255-30341-0/minicluster-data/ts-0-root/wals/1b6ad3af72e843869bcb40021fbb0eca/wal-000000025 (ops 119-123)
I20260812 06:17:21.625535 30675 maintenance_manager.cc:643] P fd53452bc3094c70bc576aac396a4ddc: LogGCOp(1b6ad3af72e843869bcb40021fbb0eca) complete. Timing: real 0.028s	user 0.001s	sys 0.023s Metrics: {}
I20260812 06:17:21.626106 30742 maintenance_manager.cc:419] P fd53452bc3094c70bc576aac396a4ddc: Scheduling FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca): perf score=3.181125
I20260812 06:17:21.639539 30675 maintenance_manager.cc:643] P fd53452bc3094c70bc576aac396a4ddc: FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca) complete. Timing: real 0.013s	user 0.002s	sys 0.009s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4792,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:21.640053 30742 maintenance_manager.cc:419] P fd53452bc3094c70bc576aac396a4ddc: Scheduling LogGCOp(1b6ad3af72e843869bcb40021fbb0eca): free 12017983 bytes of WAL
I20260812 06:17:21.640290 30675 log_reader.cc:385] T 1b6ad3af72e843869bcb40021fbb0eca: removed 1 log segments from log reader
I20260812 06:17:21.640334 30675 log.cc:1079] T 1b6ad3af72e843869bcb40021fbb0eca P fd53452bc3094c70bc576aac396a4ddc: Deleting log segment in path: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431940255-30341-0/minicluster-data/ts-0-root/wals/1b6ad3af72e843869bcb40021fbb0eca/wal-000000026 (ops 124-128)
I20260812 06:17:21.643002 30675 maintenance_manager.cc:643] P fd53452bc3094c70bc576aac396a4ddc: LogGCOp(1b6ad3af72e843869bcb40021fbb0eca) complete. Timing: real 0.003s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:17:21.643370 30742 maintenance_manager.cc:419] P fd53452bc3094c70bc576aac396a4ddc: Scheduling UndoDeltaBlockGCOp(1b6ad3af72e843869bcb40021fbb0eca): 472 bytes on disk
I20260812 06:17:21.643822 30675 maintenance_manager.cc:643] P fd53452bc3094c70bc576aac396a4ddc: UndoDeltaBlockGCOp(1b6ad3af72e843869bcb40021fbb0eca) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":64,"lbm_reads_lt_1ms":4}
I20260812 06:17:21.644325 30742 maintenance_manager.cc:419] P fd53452bc3094c70bc576aac396a4ddc: Scheduling FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca): perf score=2.188937
I20260812 06:17:21.656862 30675 maintenance_manager.cc:643] P fd53452bc3094c70bc576aac396a4ddc: FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca) complete. Timing: real 0.012s	user 0.003s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4356,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:21.657359 30742 maintenance_manager.cc:419] P fd53452bc3094c70bc576aac396a4ddc: Scheduling MajorDeltaCompactionOp(1b6ad3af72e843869bcb40021fbb0eca): perf score=1.000000
I20260812 06:17:21.829834 30675 maintenance_manager.cc:643] P fd53452bc3094c70bc576aac396a4ddc: MajorDeltaCompactionOp(1b6ad3af72e843869bcb40021fbb0eca) complete. Timing: real 0.172s	user 0.124s	sys 0.048s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28754433,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":497,"lbm_read_time_us":13157,"lbm_reads_lt_1ms":666,"lbm_write_time_us":34786,"lbm_writes_lt_1ms":643,"mutex_wait_us":48,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":7680,"thread_start_us":108,"threads_started":1,"update_count":3000}
I20260812 06:17:21.830945 30742 maintenance_manager.cc:419] P fd53452bc3094c70bc576aac396a4ddc: Scheduling FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca): perf score=14.095187
I20260812 06:17:21.879427 30675 maintenance_manager.cc:643] P fd53452bc3094c70bc576aac396a4ddc: FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca) complete. Timing: real 0.048s	user 0.033s	sys 0.012s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20408,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:21.879971 30742 maintenance_manager.cc:419] P fd53452bc3094c70bc576aac396a4ddc: Scheduling FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca): perf score=2.188937
I20260812 06:17:21.890844 30675 maintenance_manager.cc:643] P fd53452bc3094c70bc576aac396a4ddc: FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca) complete. Timing: real 0.011s	user 0.004s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4065,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:21.891417 30742 maintenance_manager.cc:419] P fd53452bc3094c70bc576aac396a4ddc: Scheduling MajorDeltaCompactionOp(1b6ad3af72e843869bcb40021fbb0eca): perf score=1.000000
I20260812 06:17:22.046252 30675 maintenance_manager.cc:643] P fd53452bc3094c70bc576aac396a4ddc: MajorDeltaCompactionOp(1b6ad3af72e843869bcb40021fbb0eca) complete. Timing: real 0.155s	user 0.120s	sys 0.034s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24651795,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":601,"lbm_read_time_us":10978,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31215,"lbm_writes_lt_1ms":543,"mutex_wait_us":78,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":15616,"update_count":2500}
I20260812 06:17:22.048436 30742 maintenance_manager.cc:419] P fd53452bc3094c70bc576aac396a4ddc: Scheduling FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca): perf score=10.126437
I20260812 06:17:22.090463 30675 maintenance_manager.cc:643] P fd53452bc3094c70bc576aac396a4ddc: FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca) complete. Timing: real 0.041s	user 0.025s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18500,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:22.091091 30742 maintenance_manager.cc:419] P fd53452bc3094c70bc576aac396a4ddc: Scheduling FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca): perf score=2.188937
I20260812 06:17:22.102522 30675 maintenance_manager.cc:643] P fd53452bc3094c70bc576aac396a4ddc: FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4220,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:22.103427 30742 maintenance_manager.cc:419] P fd53452bc3094c70bc576aac396a4ddc: Scheduling MajorDeltaCompactionOp(1b6ad3af72e843869bcb40021fbb0eca): perf score=1.000000
I20260812 06:17:22.233387 30675 maintenance_manager.cc:643] P fd53452bc3094c70bc576aac396a4ddc: MajorDeltaCompactionOp(1b6ad3af72e843869bcb40021fbb0eca) complete. Timing: real 0.130s	user 0.089s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20549382,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":521,"lbm_read_time_us":9908,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23750,"lbm_writes_lt_1ms":443,"mutex_wait_us":117,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":25088,"update_count":2000}
I20260812 06:17:22.234154 30742 maintenance_manager.cc:419] P fd53452bc3094c70bc576aac396a4ddc: Scheduling FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca): perf score=10.126437
I20260812 06:17:22.275084 30675 maintenance_manager.cc:643] P fd53452bc3094c70bc576aac396a4ddc: FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca) complete. Timing: real 0.041s	user 0.035s	sys 0.004s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":17822,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:22.275703 30742 maintenance_manager.cc:419] P fd53452bc3094c70bc576aac396a4ddc: Scheduling FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca): perf score=2.188937
I20260812 06:17:22.288476 30675 maintenance_manager.cc:643] P fd53452bc3094c70bc576aac396a4ddc: FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca) complete. Timing: real 0.013s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4549,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:22.289000 30742 maintenance_manager.cc:419] P fd53452bc3094c70bc576aac396a4ddc: Scheduling MajorDeltaCompactionOp(1b6ad3af72e843869bcb40021fbb0eca): perf score=1.000000
I20260812 06:17:22.423975 30675 maintenance_manager.cc:643] P fd53452bc3094c70bc576aac396a4ddc: MajorDeltaCompactionOp(1b6ad3af72e843869bcb40021fbb0eca) complete. Timing: real 0.135s	user 0.110s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20549381,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":651,"lbm_read_time_us":11174,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26814,"lbm_writes_lt_1ms":443,"mutex_wait_us":285,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":37888,"update_count":2000}
I20260812 06:17:22.424556 30742 maintenance_manager.cc:419] P fd53452bc3094c70bc576aac396a4ddc: Scheduling FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca): perf score=10.126437
I20260812 06:17:22.477943 30675 maintenance_manager.cc:643] P fd53452bc3094c70bc576aac396a4ddc: FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca) complete. Timing: real 0.053s	user 0.024s	sys 0.022s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16233,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:22.478497 30742 maintenance_manager.cc:419] P fd53452bc3094c70bc576aac396a4ddc: Scheduling FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca): perf score=2.188937
I20260812 06:17:22.490198 30675 maintenance_manager.cc:643] P fd53452bc3094c70bc576aac396a4ddc: FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca) complete. Timing: real 0.011s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4327,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:22.490810 30742 maintenance_manager.cc:419] P fd53452bc3094c70bc576aac396a4ddc: Scheduling MajorDeltaCompactionOp(1b6ad3af72e843869bcb40021fbb0eca): perf score=1.000000
I20260812 06:17:22.653838 30675 maintenance_manager.cc:643] P fd53452bc3094c70bc576aac396a4ddc: MajorDeltaCompactionOp(1b6ad3af72e843869bcb40021fbb0eca) complete. Timing: real 0.163s	user 0.131s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20549382,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":329,"lbm_read_time_us":14595,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25682,"lbm_writes_lt_1ms":443,"mutex_wait_us":40,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":27136,"update_count":2000}
I20260812 06:17:22.654633 30742 maintenance_manager.cc:419] P fd53452bc3094c70bc576aac396a4ddc: Scheduling FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca): perf score=10.126437
I20260812 06:17:22.701920 30675 maintenance_manager.cc:643] P fd53452bc3094c70bc576aac396a4ddc: FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca) complete. Timing: real 0.047s	user 0.023s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18853,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:22.702438 30742 maintenance_manager.cc:419] P fd53452bc3094c70bc576aac396a4ddc: Scheduling FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca): perf score=2.188937
I20260812 06:17:22.714082 30675 maintenance_manager.cc:643] P fd53452bc3094c70bc576aac396a4ddc: FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca) complete. Timing: real 0.011s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4251,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:22.714825 30742 maintenance_manager.cc:419] P fd53452bc3094c70bc576aac396a4ddc: Scheduling MajorDeltaCompactionOp(1b6ad3af72e843869bcb40021fbb0eca): perf score=1.000000
I20260812 06:17:22.840306 30675 maintenance_manager.cc:643] P fd53452bc3094c70bc576aac396a4ddc: MajorDeltaCompactionOp(1b6ad3af72e843869bcb40021fbb0eca) complete. Timing: real 0.125s	user 0.092s	sys 0.033s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20549382,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":933,"lbm_read_time_us":7837,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25698,"lbm_writes_lt_1ms":443,"mutex_wait_us":288,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:22.841079 30742 maintenance_manager.cc:419] P fd53452bc3094c70bc576aac396a4ddc: Scheduling FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca): perf score=10.126437
I20260812 06:17:22.883397 30675 maintenance_manager.cc:643] P fd53452bc3094c70bc576aac396a4ddc: FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca) complete. Timing: real 0.042s	user 0.026s	sys 0.012s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17269,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:22.883982 30742 maintenance_manager.cc:419] P fd53452bc3094c70bc576aac396a4ddc: Scheduling FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca): perf score=2.188937
I20260812 06:17:22.895651 30675 maintenance_manager.cc:643] P fd53452bc3094c70bc576aac396a4ddc: FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4177,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:22.896306 30742 maintenance_manager.cc:419] P fd53452bc3094c70bc576aac396a4ddc: Scheduling MajorDeltaCompactionOp(1b6ad3af72e843869bcb40021fbb0eca): perf score=1.000000
I20260812 06:17:23.028162 30675 maintenance_manager.cc:643] P fd53452bc3094c70bc576aac396a4ddc: MajorDeltaCompactionOp(1b6ad3af72e843869bcb40021fbb0eca) complete. Timing: real 0.132s	user 0.103s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20549383,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1122,"lbm_read_time_us":10326,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24505,"lbm_writes_lt_1ms":443,"mutex_wait_us":303,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":22144,"update_count":2000}
I20260812 06:17:23.028853 30742 maintenance_manager.cc:419] P fd53452bc3094c70bc576aac396a4ddc: Scheduling FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca): perf score=10.126437
I20260812 06:17:23.067750 30675 maintenance_manager.cc:643] P fd53452bc3094c70bc576aac396a4ddc: FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca) complete. Timing: real 0.039s	user 0.025s	sys 0.007s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":14949,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:23.068282 30742 maintenance_manager.cc:419] P fd53452bc3094c70bc576aac396a4ddc: Scheduling FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca): perf score=2.188937
I20260812 06:17:23.081331 30675 maintenance_manager.cc:643] P fd53452bc3094c70bc576aac396a4ddc: FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca) complete. Timing: real 0.013s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4473,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:23.081943 30742 maintenance_manager.cc:419] P fd53452bc3094c70bc576aac396a4ddc: Scheduling FlushMRSOp(1b6ad3af72e843869bcb40021fbb0eca): perf score=1.000000
I20260812 06:17:23.115285 30675 maintenance_manager.cc:643] P fd53452bc3094c70bc576aac396a4ddc: FlushMRSOp(1b6ad3af72e843869bcb40021fbb0eca) complete. Timing: real 0.033s	user 0.027s	sys 0.005s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":78,"dirs.run_cpu_time_us":249,"dirs.run_wall_time_us":1742,"drs_written":1,"lbm_read_time_us":42,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1724,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:17:23.116070 30742 maintenance_manager.cc:419] P fd53452bc3094c70bc576aac396a4ddc: Scheduling LogGCOp(1b6ad3af72e843869bcb40021fbb0eca): free 121006692 bytes of WAL
I20260812 06:17:23.116331 30675 log_reader.cc:385] T 1b6ad3af72e843869bcb40021fbb0eca: removed 12 log segments from log reader
I20260812 06:17:23.116374 30675 log.cc:1079] T 1b6ad3af72e843869bcb40021fbb0eca P fd53452bc3094c70bc576aac396a4ddc: Deleting log segment in path: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431940255-30341-0/minicluster-data/ts-0-root/wals/1b6ad3af72e843869bcb40021fbb0eca/wal-000000027 (ops 129-133)
I20260812 06:17:23.116405 30675 log.cc:1079] T 1b6ad3af72e843869bcb40021fbb0eca P fd53452bc3094c70bc576aac396a4ddc: Deleting log segment in path: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431940255-30341-0/minicluster-data/ts-0-root/wals/1b6ad3af72e843869bcb40021fbb0eca/wal-000000028 (ops 134-138)
I20260812 06:17:23.116480 30675 log.cc:1079] T 1b6ad3af72e843869bcb40021fbb0eca P fd53452bc3094c70bc576aac396a4ddc: Deleting log segment in path: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431940255-30341-0/minicluster-data/ts-0-root/wals/1b6ad3af72e843869bcb40021fbb0eca/wal-000000029 (ops 139-143)
I20260812 06:17:23.116513 30675 log.cc:1079] T 1b6ad3af72e843869bcb40021fbb0eca P fd53452bc3094c70bc576aac396a4ddc: Deleting log segment in path: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431940255-30341-0/minicluster-data/ts-0-root/wals/1b6ad3af72e843869bcb40021fbb0eca/wal-000000030 (ops 144-148)
I20260812 06:17:23.116556 30675 log.cc:1079] T 1b6ad3af72e843869bcb40021fbb0eca P fd53452bc3094c70bc576aac396a4ddc: Deleting log segment in path: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431940255-30341-0/minicluster-data/ts-0-root/wals/1b6ad3af72e843869bcb40021fbb0eca/wal-000000031 (ops 149-153)
I20260812 06:17:23.116600 30675 log.cc:1079] T 1b6ad3af72e843869bcb40021fbb0eca P fd53452bc3094c70bc576aac396a4ddc: Deleting log segment in path: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431940255-30341-0/minicluster-data/ts-0-root/wals/1b6ad3af72e843869bcb40021fbb0eca/wal-000000032 (ops 154-158)
I20260812 06:17:23.116668 30675 log.cc:1079] T 1b6ad3af72e843869bcb40021fbb0eca P fd53452bc3094c70bc576aac396a4ddc: Deleting log segment in path: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431940255-30341-0/minicluster-data/ts-0-root/wals/1b6ad3af72e843869bcb40021fbb0eca/wal-000000033 (ops 159-163)
I20260812 06:17:23.116696 30675 log.cc:1079] T 1b6ad3af72e843869bcb40021fbb0eca P fd53452bc3094c70bc576aac396a4ddc: Deleting log segment in path: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431940255-30341-0/minicluster-data/ts-0-root/wals/1b6ad3af72e843869bcb40021fbb0eca/wal-000000034 (ops 164-168)
I20260812 06:17:23.116739 30675 log.cc:1079] T 1b6ad3af72e843869bcb40021fbb0eca P fd53452bc3094c70bc576aac396a4ddc: Deleting log segment in path: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431940255-30341-0/minicluster-data/ts-0-root/wals/1b6ad3af72e843869bcb40021fbb0eca/wal-000000035 (ops 169-173)
I20260812 06:17:23.116783 30675 log.cc:1079] T 1b6ad3af72e843869bcb40021fbb0eca P fd53452bc3094c70bc576aac396a4ddc: Deleting log segment in path: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431940255-30341-0/minicluster-data/ts-0-root/wals/1b6ad3af72e843869bcb40021fbb0eca/wal-000000036 (ops 174-178)
I20260812 06:17:23.116824 30675 log.cc:1079] T 1b6ad3af72e843869bcb40021fbb0eca P fd53452bc3094c70bc576aac396a4ddc: Deleting log segment in path: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431940255-30341-0/minicluster-data/ts-0-root/wals/1b6ad3af72e843869bcb40021fbb0eca/wal-000000037 (ops 179-182)
I20260812 06:17:23.116865 30675 log.cc:1079] T 1b6ad3af72e843869bcb40021fbb0eca P fd53452bc3094c70bc576aac396a4ddc: Deleting log segment in path: /tmp/dist-test-taskYW_Mc1/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431940255-30341-0/minicluster-data/ts-0-root/wals/1b6ad3af72e843869bcb40021fbb0eca/wal-000000038 (ops 183-187)
I20260812 06:17:23.144053 30675 maintenance_manager.cc:643] P fd53452bc3094c70bc576aac396a4ddc: LogGCOp(1b6ad3af72e843869bcb40021fbb0eca) complete. Timing: real 0.028s	user 0.003s	sys 0.023s Metrics: {}
I20260812 06:17:23.144490 30742 maintenance_manager.cc:419] P fd53452bc3094c70bc576aac396a4ddc: Scheduling UndoDeltaBlockGCOp(1b6ad3af72e843869bcb40021fbb0eca): 482 bytes on disk
I20260812 06:17:23.145035 30675 maintenance_manager.cc:643] P fd53452bc3094c70bc576aac396a4ddc: UndoDeltaBlockGCOp(1b6ad3af72e843869bcb40021fbb0eca) 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:23.145694 30742 maintenance_manager.cc:419] P fd53452bc3094c70bc576aac396a4ddc: Scheduling FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca): perf score=5.165500
I20260812 06:17:23.166551 30675 maintenance_manager.cc:643] P fd53452bc3094c70bc576aac396a4ddc: FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca) complete. Timing: real 0.021s	user 0.015s	sys 0.004s Metrics: {"bytes_written":6482066,"delete_count":0,"lbm_write_time_us":8579,"lbm_writes_lt_1ms":161,"reinsert_count":0,"update_count":790}
I20260812 06:17:23.167253 30742 maintenance_manager.cc:419] P fd53452bc3094c70bc576aac396a4ddc: Scheduling FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca): perf score=1.000000
I20260812 06:17:23.175693 30675 maintenance_manager.cc:643] P fd53452bc3094c70bc576aac396a4ddc: FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca) complete. Timing: real 0.008s	user 0.006s	sys 0.000s Metrics: {"bytes_written":1723202,"delete_count":0,"lbm_write_time_us":2472,"lbm_writes_lt_1ms":45,"reinsert_count":0,"update_count":210}
I20260812 06:17:23.176370 30742 maintenance_manager.cc:419] P fd53452bc3094c70bc576aac396a4ddc: Scheduling MajorDeltaCompactionOp(1b6ad3af72e843869bcb40021fbb0eca): perf score=1.000000
I20260812 06:17:23.368299 30675 maintenance_manager.cc:643] P fd53452bc3094c70bc576aac396a4ddc: MajorDeltaCompactionOp(1b6ad3af72e843869bcb40021fbb0eca) complete. Timing: real 0.192s	user 0.177s	sys 0.013s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28754388,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":3911,"lbm_read_time_us":13026,"lbm_reads_lt_1ms":666,"lbm_write_time_us":38322,"lbm_writes_lt_1ms":643,"mutex_wait_us":1588,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2944,"thread_start_us":111,"threads_started":1,"update_count":3000}
I20260812 06:17:23.369194 30742 maintenance_manager.cc:419] P fd53452bc3094c70bc576aac396a4ddc: Scheduling FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca): perf score=14.095187
I20260812 06:17:23.420039 30341 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.200s	user 1.899s	sys 0.130s
I20260812 06:17:23.423256 30675 maintenance_manager.cc:643] P fd53452bc3094c70bc576aac396a4ddc: FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca) complete. Timing: real 0.054s	user 0.039s	sys 0.008s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":21421,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:23.423738 30742 maintenance_manager.cc:419] P fd53452bc3094c70bc576aac396a4ddc: Scheduling FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca): perf score=2.188937
I20260812 06:17:23.434100 30675 maintenance_manager.cc:643] P fd53452bc3094c70bc576aac396a4ddc: FlushDeltaMemStoresOp(1b6ad3af72e843869bcb40021fbb0eca) complete. Timing: real 0.010s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4288,"lbm_writes_lt_1ms":103,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":500}
I20260812 06:17:23.434633 30742 maintenance_manager.cc:419] P fd53452bc3094c70bc576aac396a4ddc: Scheduling MajorDeltaCompactionOp(1b6ad3af72e843869bcb40021fbb0eca): perf score=1.000000
I20260812 06:17:23.466308 30341 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.046s	user 0.002s	sys 0.000s
I20260812 06:17:23.466900 30341 tablet_server.cc:179] TabletServer@127.29.161.65:0 shutting down...
I20260812 06:17:23.544795 30675 maintenance_manager.cc:643] P fd53452bc3094c70bc576aac396a4ddc: MajorDeltaCompactionOp(1b6ad3af72e843869bcb40021fbb0eca) complete. Timing: real 0.110s	user 0.083s	sys 0.026s Metrics: {"cfile_cache_hit":401,"cfile_cache_hit_bytes":16409769,"cfile_cache_miss":131,"cfile_cache_miss_bytes":8242025,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":424,"lbm_read_time_us":3296,"lbm_reads_lt_1ms":163,"lbm_write_time_us":25033,"lbm_writes_lt_1ms":543,"mutex_wait_us":62,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12928,"update_count":2500}
I20260812 06:17:23.545511 30341 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:23.545827 30341 tablet_replica.cc:333] T 1b6ad3af72e843869bcb40021fbb0eca P fd53452bc3094c70bc576aac396a4ddc: stopping tablet replica
I20260812 06:17:23.545986 30341 raft_consensus.cc:2243] T 1b6ad3af72e843869bcb40021fbb0eca P fd53452bc3094c70bc576aac396a4ddc [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:23.546187 30341 raft_consensus.cc:2272] T 1b6ad3af72e843869bcb40021fbb0eca P fd53452bc3094c70bc576aac396a4ddc [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:23.561306 30341 tablet_server.cc:196] TabletServer@127.29.161.65:0 shutdown complete.
I20260812 06:17:23.591374 30341 master.cc:562] Master@127.29.161.126:42333 shutting down...
I20260812 06:17:23.595515 30341 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 1be2e7b1650c498ba330a919d34c9200 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:23.595741 30341 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 1be2e7b1650c498ba330a919d34c9200 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:23.595844 30341 tablet_replica.cc:333] T 00000000000000000000000000000000 P 1be2e7b1650c498ba330a919d34c9200: stopping tablet replica
I20260812 06:17:23.608330 30341 master.cc:584] Master@127.29.161.126:42333 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5869 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11753 ms total)

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