[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:20:22.179365 19292 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.18.215.62:45791
I20260812 06:20:22.180365 19292 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:20:22.180975 19292 file_cache.cc:504] Constructed file cache file cache with capacity 419430
I20260812 06:20:22.187229 19292 server_base.cc:1061] running on GCE node
W20260812 06:20:22.187287 19301 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:22.187386 19299 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:20:22.187529 19298 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:22.188012 19292 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:22.188112 19292 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:22.188154 19292 hybrid_clock.cc:648] HybridClock initialized: now 1786515622188152 us; error 0 us; skew 500 ppm
I20260812 06:20:22.189850 19292 webserver.cc:533] Webserver started at http://127.18.215.62:42673/ using document root <none> and password file <none>
I20260812 06:20:22.190384 19292 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:22.190442 19292 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:22.190689 19292 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:22.192335 19292 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515622168709-19292-0/minicluster-data/master-0-root/instance:
uuid: "554617fdcd4d46f48555ab345aceb015"
format_stamp: "Formatted at 2026-08-12 06:20:22 on dist-test-slave-vq2q"
I20260812 06:20:22.195897 19292 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.005s	sys 0.000s
I20260812 06:20:22.198050 19306 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:22.199028 19292 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:20:22.199136 19292 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515622168709-19292-0/minicluster-data/master-0-root
uuid: "554617fdcd4d46f48555ab345aceb015"
format_stamp: "Formatted at 2026-08-12 06:20:22 on dist-test-slave-vq2q"
I20260812 06:20:22.199223 19292 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515622168709-19292-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515622168709-19292-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515622168709-19292-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:22.217474 19292 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:22.218103 19292 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:20:22.218281 19292 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:22.225672 19367 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.18.215.62:45791 every 8 connection(s)
I20260812 06:20:22.225669 19292 rpc_server.cc:307] RPC server started. Bound to: 127.18.215.62:45791
I20260812 06:20:22.227988 19368 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:22.233407 19368 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 554617fdcd4d46f48555ab345aceb015: Bootstrap starting.
I20260812 06:20:22.235783 19368 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 554617fdcd4d46f48555ab345aceb015: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:22.236690 19368 log.cc:826] T 00000000000000000000000000000000 P 554617fdcd4d46f48555ab345aceb015: Log is configured to *not* fsync() on all Append() calls
I20260812 06:20:22.238284 19368 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 554617fdcd4d46f48555ab345aceb015: No bootstrap required, opened a new log
I20260812 06:20:22.240965 19368 raft_consensus.cc:359] T 00000000000000000000000000000000 P 554617fdcd4d46f48555ab345aceb015 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "554617fdcd4d46f48555ab345aceb015" member_type: VOTER }
I20260812 06:20:22.241125 19368 raft_consensus.cc:385] T 00000000000000000000000000000000 P 554617fdcd4d46f48555ab345aceb015 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:22.241209 19368 raft_consensus.cc:740] T 00000000000000000000000000000000 P 554617fdcd4d46f48555ab345aceb015 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 554617fdcd4d46f48555ab345aceb015, State: Initialized, Role: FOLLOWER
I20260812 06:20:22.241771 19368 consensus_queue.cc:260] T 00000000000000000000000000000000 P 554617fdcd4d46f48555ab345aceb015 [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: "554617fdcd4d46f48555ab345aceb015" member_type: VOTER }
I20260812 06:20:22.241914 19368 raft_consensus.cc:399] T 00000000000000000000000000000000 P 554617fdcd4d46f48555ab345aceb015 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:22.241981 19368 raft_consensus.cc:493] T 00000000000000000000000000000000 P 554617fdcd4d46f48555ab345aceb015 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:22.242096 19368 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 554617fdcd4d46f48555ab345aceb015 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:22.242813 19368 raft_consensus.cc:515] T 00000000000000000000000000000000 P 554617fdcd4d46f48555ab345aceb015 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "554617fdcd4d46f48555ab345aceb015" member_type: VOTER }
I20260812 06:20:22.243219 19368 leader_election.cc:304] T 00000000000000000000000000000000 P 554617fdcd4d46f48555ab345aceb015 [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: 554617fdcd4d46f48555ab345aceb015; no voters: 
I20260812 06:20:22.243510 19368 leader_election.cc:290] T 00000000000000000000000000000000 P 554617fdcd4d46f48555ab345aceb015 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:22.243638 19372 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 554617fdcd4d46f48555ab345aceb015 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:22.243839 19372 raft_consensus.cc:697] T 00000000000000000000000000000000 P 554617fdcd4d46f48555ab345aceb015 [term 1 LEADER]: Becoming Leader. State: Replica: 554617fdcd4d46f48555ab345aceb015, State: Running, Role: LEADER
I20260812 06:20:22.244204 19372 consensus_queue.cc:237] T 00000000000000000000000000000000 P 554617fdcd4d46f48555ab345aceb015 [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: "554617fdcd4d46f48555ab345aceb015" member_type: VOTER }
I20260812 06:20:22.244391 19368 sys_catalog.cc:565] T 00000000000000000000000000000000 P 554617fdcd4d46f48555ab345aceb015 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:22.245829 19373 sys_catalog.cc:455] T 00000000000000000000000000000000 P 554617fdcd4d46f48555ab345aceb015 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "554617fdcd4d46f48555ab345aceb015" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "554617fdcd4d46f48555ab345aceb015" member_type: VOTER } }
I20260812 06:20:22.245940 19373 sys_catalog.cc:458] T 00000000000000000000000000000000 P 554617fdcd4d46f48555ab345aceb015 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:22.246203 19374 sys_catalog.cc:455] T 00000000000000000000000000000000 P 554617fdcd4d46f48555ab345aceb015 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 554617fdcd4d46f48555ab345aceb015. Latest consensus state: current_term: 1 leader_uuid: "554617fdcd4d46f48555ab345aceb015" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "554617fdcd4d46f48555ab345aceb015" member_type: VOTER } }
I20260812 06:20:22.246281 19374 sys_catalog.cc:458] T 00000000000000000000000000000000 P 554617fdcd4d46f48555ab345aceb015 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:22.246371 19381 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:22.246657 19292 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:22.248538 19381 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:22.252904 19381 catalog_manager.cc:1383] Generated new cluster ID: d0316779b8a04bb3ac85425395e09a5d
I20260812 06:20:22.252975 19381 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:22.269562 19381 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:22.270674 19381 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:22.283339 19381 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 554617fdcd4d46f48555ab345aceb015: Generated new TSK 0
I20260812 06:20:22.284017 19381 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:22.311661 19292 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:22.314293 19394 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:22.314409 19398 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:22.314519 19395 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:22.314579 19292 server_base.cc:1061] running on GCE node
I20260812 06:20:22.314837 19292 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:22.314893 19292 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:22.314915 19292 hybrid_clock.cc:648] HybridClock initialized: now 1786515622314915 us; error 0 us; skew 500 ppm
I20260812 06:20:22.315827 19292 webserver.cc:533] Webserver started at http://127.18.215.1:39645/ using document root <none> and password file <none>
I20260812 06:20:22.315996 19292 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:22.316056 19292 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:22.316133 19292 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:22.316581 19292 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515622168709-19292-0/minicluster-data/ts-0-root/instance:
uuid: "e270a6124b614d3db11b67b1b40cb342"
format_stamp: "Formatted at 2026-08-12 06:20:22 on dist-test-slave-vq2q"
I20260812 06:20:22.318398 19292 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:20:22.319478 19406 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:22.319748 19292 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:20:22.319828 19292 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515622168709-19292-0/minicluster-data/ts-0-root
uuid: "e270a6124b614d3db11b67b1b40cb342"
format_stamp: "Formatted at 2026-08-12 06:20:22 on dist-test-slave-vq2q"
I20260812 06:20:22.319897 19292 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515622168709-19292-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515622168709-19292-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515622168709-19292-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:22.333171 19292 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:22.333679 19292 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:22.334223 19292 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:22.335227 19292 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:22.335290 19292 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:22.335355 19292 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:22.335386 19292 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:22.342123 19292 rpc_server.cc:307] RPC server started. Bound to: 127.18.215.1:43609
I20260812 06:20:22.342314 19477 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.18.215.1:43609 every 8 connection(s)
I20260812 06:20:22.355055 19480 heartbeater.cc:344] Connected to a master server at 127.18.215.62:45791
I20260812 06:20:22.355296 19480 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:22.355737 19480 heartbeater.cc:507] Master 127.18.215.62:45791 requested a full tablet report, sending...
I20260812 06:20:22.357163 19328 ts_manager.cc:194] Registered new tserver with Master: e270a6124b614d3db11b67b1b40cb342 (127.18.215.1:43609)
I20260812 06:20:22.357280 19292 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.014483006s
I20260812 06:20:22.358381 19328 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:37078
I20260812 06:20:22.366205 19328 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:37090:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:20:22.380118 19437 tablet_service.cc:1511] Processing CreateTablet for tablet f9bf63ed0fcd43989b28e75e9ae5ab36 (DEFAULT_TABLE table=heavy-update-compaction-test [id=a7b4baf7358647e7ba4726abe45edec5]), partition=
I20260812 06:20:22.380553 19437 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet f9bf63ed0fcd43989b28e75e9ae5ab36. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:22.382737 19494 tablet_bootstrap.cc:492] T f9bf63ed0fcd43989b28e75e9ae5ab36 P e270a6124b614d3db11b67b1b40cb342: Bootstrap starting.
I20260812 06:20:22.384262 19494 tablet_bootstrap.cc:654] T f9bf63ed0fcd43989b28e75e9ae5ab36 P e270a6124b614d3db11b67b1b40cb342: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:22.385594 19494 tablet_bootstrap.cc:492] T f9bf63ed0fcd43989b28e75e9ae5ab36 P e270a6124b614d3db11b67b1b40cb342: No bootstrap required, opened a new log
I20260812 06:20:22.385704 19494 ts_tablet_manager.cc:1403] T f9bf63ed0fcd43989b28e75e9ae5ab36 P e270a6124b614d3db11b67b1b40cb342: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:20:22.386250 19494 raft_consensus.cc:359] T f9bf63ed0fcd43989b28e75e9ae5ab36 P e270a6124b614d3db11b67b1b40cb342 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e270a6124b614d3db11b67b1b40cb342" member_type: VOTER last_known_addr { host: "127.18.215.1" port: 43609 } }
I20260812 06:20:22.386385 19494 raft_consensus.cc:385] T f9bf63ed0fcd43989b28e75e9ae5ab36 P e270a6124b614d3db11b67b1b40cb342 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:22.386427 19494 raft_consensus.cc:740] T f9bf63ed0fcd43989b28e75e9ae5ab36 P e270a6124b614d3db11b67b1b40cb342 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: e270a6124b614d3db11b67b1b40cb342, State: Initialized, Role: FOLLOWER
I20260812 06:20:22.386559 19494 consensus_queue.cc:260] T f9bf63ed0fcd43989b28e75e9ae5ab36 P e270a6124b614d3db11b67b1b40cb342 [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: "e270a6124b614d3db11b67b1b40cb342" member_type: VOTER last_known_addr { host: "127.18.215.1" port: 43609 } }
I20260812 06:20:22.386721 19494 raft_consensus.cc:399] T f9bf63ed0fcd43989b28e75e9ae5ab36 P e270a6124b614d3db11b67b1b40cb342 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:22.386811 19494 raft_consensus.cc:493] T f9bf63ed0fcd43989b28e75e9ae5ab36 P e270a6124b614d3db11b67b1b40cb342 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:22.386901 19494 raft_consensus.cc:3060] T f9bf63ed0fcd43989b28e75e9ae5ab36 P e270a6124b614d3db11b67b1b40cb342 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:22.387856 19494 raft_consensus.cc:515] T f9bf63ed0fcd43989b28e75e9ae5ab36 P e270a6124b614d3db11b67b1b40cb342 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e270a6124b614d3db11b67b1b40cb342" member_type: VOTER last_known_addr { host: "127.18.215.1" port: 43609 } }
I20260812 06:20:22.388016 19494 leader_election.cc:304] T f9bf63ed0fcd43989b28e75e9ae5ab36 P e270a6124b614d3db11b67b1b40cb342 [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: e270a6124b614d3db11b67b1b40cb342; no voters: 
I20260812 06:20:22.388226 19494 leader_election.cc:290] T f9bf63ed0fcd43989b28e75e9ae5ab36 P e270a6124b614d3db11b67b1b40cb342 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:22.388331 19496 raft_consensus.cc:2804] T f9bf63ed0fcd43989b28e75e9ae5ab36 P e270a6124b614d3db11b67b1b40cb342 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:22.388543 19496 raft_consensus.cc:697] T f9bf63ed0fcd43989b28e75e9ae5ab36 P e270a6124b614d3db11b67b1b40cb342 [term 1 LEADER]: Becoming Leader. State: Replica: e270a6124b614d3db11b67b1b40cb342, State: Running, Role: LEADER
I20260812 06:20:22.388604 19494 ts_tablet_manager.cc:1434] T f9bf63ed0fcd43989b28e75e9ae5ab36 P e270a6124b614d3db11b67b1b40cb342: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:20:22.388912 19480 heartbeater.cc:499] Master 127.18.215.62:45791 was elected leader, sending a full tablet report...
I20260812 06:20:22.388978 19496 consensus_queue.cc:237] T f9bf63ed0fcd43989b28e75e9ae5ab36 P e270a6124b614d3db11b67b1b40cb342 [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: "e270a6124b614d3db11b67b1b40cb342" member_type: VOTER last_known_addr { host: "127.18.215.1" port: 43609 } }
I20260812 06:20:22.391760 19328 catalog_manager.cc:5719] T f9bf63ed0fcd43989b28e75e9ae5ab36 P e270a6124b614d3db11b67b1b40cb342 reported cstate change: term changed from 0 to 1, leader changed from <none> to e270a6124b614d3db11b67b1b40cb342 (127.18.215.1). New cstate: current_term: 1 leader_uuid: "e270a6124b614d3db11b67b1b40cb342" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e270a6124b614d3db11b67b1b40cb342" member_type: VOTER last_known_addr { host: "127.18.215.1" port: 43609 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:22.453558 19292 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.054s	user 0.016s	sys 0.010s
I20260812 06:20:22.593474 19481 maintenance_manager.cc:419] P e270a6124b614d3db11b67b1b40cb342: Scheduling FlushMRSOp(f9bf63ed0fcd43989b28e75e9ae5ab36): perf score=19.054940
I20260812 06:20:22.789701 19412 maintenance_manager.cc:643] P e270a6124b614d3db11b67b1b40cb342: FlushMRSOp(f9bf63ed0fcd43989b28e75e9ae5ab36) complete. Timing: real 0.196s	user 0.129s	sys 0.065s Metrics: {"bytes_written":16245806,"cfile_init":1,"compiler_manager_pool.queue_time_us":222,"delete_count":0,"dirs.queue_time_us":53,"dirs.run_cpu_time_us":218,"dirs.run_wall_time_us":767,"drs_written":1,"lbm_read_time_us":73,"lbm_reads_lt_1ms":4,"lbm_write_time_us":46307,"lbm_writes_lt_1ms":863,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"spinlock_wait_cycles":336128,"thread_start_us":116,"threads_started":1,"update_count":1980}
I20260812 06:20:22.791257 19481 maintenance_manager.cc:419] P e270a6124b614d3db11b67b1b40cb342: Scheduling LogGCOp(f9bf63ed0fcd43989b28e75e9ae5ab36): free 20743880 bytes of WAL
I20260812 06:20:22.791610 19412 log_reader.cc:385] T f9bf63ed0fcd43989b28e75e9ae5ab36: removed 2 log segments from log reader
I20260812 06:20:22.791689 19412 log.cc:1079] T f9bf63ed0fcd43989b28e75e9ae5ab36 P e270a6124b614d3db11b67b1b40cb342: Deleting log segment in path: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515622168709-19292-0/minicluster-data/ts-0-root/wals/f9bf63ed0fcd43989b28e75e9ae5ab36/wal-000000001 (ops 1-6)
I20260812 06:20:22.791814 19412 log.cc:1079] T f9bf63ed0fcd43989b28e75e9ae5ab36 P e270a6124b614d3db11b67b1b40cb342: Deleting log segment in path: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515622168709-19292-0/minicluster-data/ts-0-root/wals/f9bf63ed0fcd43989b28e75e9ae5ab36/wal-000000002 (ops 7-11)
I20260812 06:20:22.796808 19412 maintenance_manager.cc:643] P e270a6124b614d3db11b67b1b40cb342: LogGCOp(f9bf63ed0fcd43989b28e75e9ae5ab36) complete. Timing: real 0.005s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:20:22.797166 19481 maintenance_manager.cc:419] P e270a6124b614d3db11b67b1b40cb342: Scheduling FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36): perf score=6.157687
I20260812 06:20:22.820437 19412 maintenance_manager.cc:643] P e270a6124b614d3db11b67b1b40cb342: FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36) complete. Timing: real 0.023s	user 0.016s	sys 0.004s Metrics: {"bytes_written":7958938,"delete_count":0,"lbm_write_time_us":9710,"lbm_writes_lt_1ms":197,"reinsert_count":0,"update_count":970}
I20260812 06:20:22.820937 19481 maintenance_manager.cc:419] P e270a6124b614d3db11b67b1b40cb342: Scheduling MajorDeltaCompactionOp(f9bf63ed0fcd43989b28e75e9ae5ab36): perf score=1.000000
I20260812 06:20:22.993530 19412 maintenance_manager.cc:643] P e270a6124b614d3db11b67b1b40cb342: MajorDeltaCompactionOp(f9bf63ed0fcd43989b28e75e9ae5ab36) complete. Timing: real 0.172s	user 0.121s	sys 0.050s Metrics: {"cfile_cache_miss":622,"cfile_cache_miss_bytes":28507861,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1147,"lbm_read_time_us":10524,"lbm_reads_lt_1ms":654,"lbm_write_time_us":29863,"lbm_writes_lt_1ms":633,"peak_mem_usage":74091738,"reinsert_count":0,"thread_start_us":351,"threads_started":5,"update_count":2950}
I20260812 06:20:22.994012 19481 maintenance_manager.cc:419] P e270a6124b614d3db11b67b1b40cb342: Scheduling FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36): perf score=14.095187
I20260812 06:20:23.050371 19412 maintenance_manager.cc:643] P e270a6124b614d3db11b67b1b40cb342: FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36) complete. Timing: real 0.056s	user 0.034s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":25587,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:23.050925 19481 maintenance_manager.cc:419] P e270a6124b614d3db11b67b1b40cb342: Scheduling UndoDeltaBlockGCOp(f9bf63ed0fcd43989b28e75e9ae5ab36): 16821648 bytes on disk
I20260812 06:20:23.051393 19412 maintenance_manager.cc:643] P e270a6124b614d3db11b67b1b40cb342: UndoDeltaBlockGCOp(f9bf63ed0fcd43989b28e75e9ae5ab36) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":44,"lbm_reads_lt_1ms":4}
I20260812 06:20:23.051828 19481 maintenance_manager.cc:419] P e270a6124b614d3db11b67b1b40cb342: Scheduling FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36): perf score=2.188937
I20260812 06:20:23.063530 19412 maintenance_manager.cc:643] P e270a6124b614d3db11b67b1b40cb342: FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36) complete. Timing: real 0.012s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4408,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:23.063968 19481 maintenance_manager.cc:419] P e270a6124b614d3db11b67b1b40cb342: Scheduling MajorDeltaCompactionOp(f9bf63ed0fcd43989b28e75e9ae5ab36): perf score=1.000000
I20260812 06:20:23.220126 19412 maintenance_manager.cc:643] P e270a6124b614d3db11b67b1b40cb342: MajorDeltaCompactionOp(f9bf63ed0fcd43989b28e75e9ae5ab36) complete. Timing: real 0.156s	user 0.091s	sys 0.064s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":141,"lbm_read_time_us":10677,"lbm_reads_lt_1ms":564,"lbm_write_time_us":25455,"lbm_writes_lt_1ms":543,"mutex_wait_us":39,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8448,"update_count":2500}
I20260812 06:20:23.220618 19481 maintenance_manager.cc:419] P e270a6124b614d3db11b67b1b40cb342: Scheduling FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36): perf score=11.118625
I20260812 06:20:23.249918 19412 maintenance_manager.cc:643] P e270a6124b614d3db11b67b1b40cb342: FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36) complete. Timing: real 0.029s	user 0.020s	sys 0.008s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":11489,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:23.250409 19481 maintenance_manager.cc:419] P e270a6124b614d3db11b67b1b40cb342: Scheduling FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36): perf score=2.188937
I20260812 06:20:23.263608 19412 maintenance_manager.cc:643] P e270a6124b614d3db11b67b1b40cb342: FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36) complete. Timing: real 0.013s	user 0.005s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4343,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:23.264266 19481 maintenance_manager.cc:419] P e270a6124b614d3db11b67b1b40cb342: Scheduling MajorDeltaCompactionOp(f9bf63ed0fcd43989b28e75e9ae5ab36): perf score=1.000000
I20260812 06:20:23.405247 19412 maintenance_manager.cc:643] P e270a6124b614d3db11b67b1b40cb342: MajorDeltaCompactionOp(f9bf63ed0fcd43989b28e75e9ae5ab36) complete. Timing: real 0.141s	user 0.100s	sys 0.038s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713263,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":240,"lbm_read_time_us":8265,"lbm_reads_lt_1ms":468,"lbm_write_time_us":22528,"lbm_writes_lt_1ms":443,"mutex_wait_us":24,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":14464,"update_count":2000}
I20260812 06:20:23.405839 19481 maintenance_manager.cc:419] P e270a6124b614d3db11b67b1b40cb342: Scheduling FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36): perf score=11.118625
I20260812 06:20:23.436091 19412 maintenance_manager.cc:643] P e270a6124b614d3db11b67b1b40cb342: FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36) complete. Timing: real 0.030s	user 0.020s	sys 0.007s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":12132,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:23.436656 19481 maintenance_manager.cc:419] P e270a6124b614d3db11b67b1b40cb342: Scheduling FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36): perf score=2.188937
I20260812 06:20:23.448184 19412 maintenance_manager.cc:643] P e270a6124b614d3db11b67b1b40cb342: FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36) complete. Timing: real 0.011s	user 0.002s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3903,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:23.448604 19481 maintenance_manager.cc:419] P e270a6124b614d3db11b67b1b40cb342: Scheduling MajorDeltaCompactionOp(f9bf63ed0fcd43989b28e75e9ae5ab36): perf score=1.000000
I20260812 06:20:23.563766 19412 maintenance_manager.cc:643] P e270a6124b614d3db11b67b1b40cb342: MajorDeltaCompactionOp(f9bf63ed0fcd43989b28e75e9ae5ab36) complete. Timing: real 0.115s	user 0.096s	sys 0.019s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713263,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":321,"lbm_read_time_us":6804,"lbm_reads_lt_1ms":464,"lbm_write_time_us":22276,"lbm_writes_lt_1ms":443,"mutex_wait_us":66,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:20:23.567129 19481 maintenance_manager.cc:419] P e270a6124b614d3db11b67b1b40cb342: Scheduling FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36): perf score=10.126437
I20260812 06:20:23.603264 19412 maintenance_manager.cc:643] P e270a6124b614d3db11b67b1b40cb342: FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36) complete. Timing: real 0.036s	user 0.025s	sys 0.009s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":12738,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:23.603813 19481 maintenance_manager.cc:419] P e270a6124b614d3db11b67b1b40cb342: Scheduling FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36): perf score=2.188937
I20260812 06:20:23.614352 19412 maintenance_manager.cc:643] P e270a6124b614d3db11b67b1b40cb342: FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36) complete. Timing: real 0.010s	user 0.000s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3516,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:23.614814 19481 maintenance_manager.cc:419] P e270a6124b614d3db11b67b1b40cb342: Scheduling MajorDeltaCompactionOp(f9bf63ed0fcd43989b28e75e9ae5ab36): perf score=1.000000
I20260812 06:20:23.732796 19412 maintenance_manager.cc:643] P e270a6124b614d3db11b67b1b40cb342: MajorDeltaCompactionOp(f9bf63ed0fcd43989b28e75e9ae5ab36) complete. Timing: real 0.118s	user 0.075s	sys 0.042s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713275,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":880,"lbm_read_time_us":7121,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22600,"lbm_writes_lt_1ms":443,"mutex_wait_us":288,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":20992,"update_count":2000}
I20260812 06:20:23.733325 19481 maintenance_manager.cc:419] P e270a6124b614d3db11b67b1b40cb342: Scheduling FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36): perf score=10.126437
I20260812 06:20:23.785399 19412 maintenance_manager.cc:643] P e270a6124b614d3db11b67b1b40cb342: FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36) complete. Timing: real 0.052s	user 0.028s	sys 0.024s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":19960,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:20:23.785952 19481 maintenance_manager.cc:419] P e270a6124b614d3db11b67b1b40cb342: Scheduling FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36): perf score=2.188937
I20260812 06:20:23.796314 19412 maintenance_manager.cc:643] P e270a6124b614d3db11b67b1b40cb342: FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3921,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:23.796761 19481 maintenance_manager.cc:419] P e270a6124b614d3db11b67b1b40cb342: Scheduling MajorDeltaCompactionOp(f9bf63ed0fcd43989b28e75e9ae5ab36): perf score=1.000000
I20260812 06:20:23.940116 19412 maintenance_manager.cc:643] P e270a6124b614d3db11b67b1b40cb342: MajorDeltaCompactionOp(f9bf63ed0fcd43989b28e75e9ae5ab36) complete. Timing: real 0.143s	user 0.102s	sys 0.039s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713273,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":188,"lbm_read_time_us":10208,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24861,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:20:23.940915 19481 maintenance_manager.cc:419] P e270a6124b614d3db11b67b1b40cb342: Scheduling FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36): perf score=10.126437
I20260812 06:20:23.986080 19412 maintenance_manager.cc:643] P e270a6124b614d3db11b67b1b40cb342: FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36) complete. Timing: real 0.045s	user 0.027s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14683,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:23.986640 19481 maintenance_manager.cc:419] P e270a6124b614d3db11b67b1b40cb342: Scheduling FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36): perf score=2.188937
I20260812 06:20:23.998912 19412 maintenance_manager.cc:643] P e270a6124b614d3db11b67b1b40cb342: FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36) complete. Timing: real 0.012s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4754,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:23.999544 19481 maintenance_manager.cc:419] P e270a6124b614d3db11b67b1b40cb342: Scheduling FlushMRSOp(f9bf63ed0fcd43989b28e75e9ae5ab36): perf score=1.000000
I20260812 06:20:24.027912 19412 maintenance_manager.cc:643] P e270a6124b614d3db11b67b1b40cb342: FlushMRSOp(f9bf63ed0fcd43989b28e75e9ae5ab36) complete. Timing: real 0.028s	user 0.026s	sys 0.001s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":69,"dirs.run_cpu_time_us":265,"dirs.run_wall_time_us":1424,"drs_written":1,"lbm_read_time_us":47,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1570,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:20:24.028740 19481 maintenance_manager.cc:419] P e270a6124b614d3db11b67b1b40cb342: Scheduling LogGCOp(f9bf63ed0fcd43989b28e75e9ae5ab36): free 124710304 bytes of WAL
I20260812 06:20:24.028975 19412 log_reader.cc:385] T f9bf63ed0fcd43989b28e75e9ae5ab36: removed 12 log segments from log reader
I20260812 06:20:24.029033 19412 log.cc:1079] T f9bf63ed0fcd43989b28e75e9ae5ab36 P e270a6124b614d3db11b67b1b40cb342: Deleting log segment in path: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515622168709-19292-0/minicluster-data/ts-0-root/wals/f9bf63ed0fcd43989b28e75e9ae5ab36/wal-000000003 (ops 12-16)
I20260812 06:20:24.029081 19412 log.cc:1079] T f9bf63ed0fcd43989b28e75e9ae5ab36 P e270a6124b614d3db11b67b1b40cb342: Deleting log segment in path: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515622168709-19292-0/minicluster-data/ts-0-root/wals/f9bf63ed0fcd43989b28e75e9ae5ab36/wal-000000004 (ops 17-21)
I20260812 06:20:24.029114 19412 log.cc:1079] T f9bf63ed0fcd43989b28e75e9ae5ab36 P e270a6124b614d3db11b67b1b40cb342: Deleting log segment in path: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515622168709-19292-0/minicluster-data/ts-0-root/wals/f9bf63ed0fcd43989b28e75e9ae5ab36/wal-000000005 (ops 22-26)
I20260812 06:20:24.029145 19412 log.cc:1079] T f9bf63ed0fcd43989b28e75e9ae5ab36 P e270a6124b614d3db11b67b1b40cb342: Deleting log segment in path: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515622168709-19292-0/minicluster-data/ts-0-root/wals/f9bf63ed0fcd43989b28e75e9ae5ab36/wal-000000006 (ops 27-31)
I20260812 06:20:24.029194 19412 log.cc:1079] T f9bf63ed0fcd43989b28e75e9ae5ab36 P e270a6124b614d3db11b67b1b40cb342: Deleting log segment in path: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515622168709-19292-0/minicluster-data/ts-0-root/wals/f9bf63ed0fcd43989b28e75e9ae5ab36/wal-000000007 (ops 32-36)
I20260812 06:20:24.029230 19412 log.cc:1079] T f9bf63ed0fcd43989b28e75e9ae5ab36 P e270a6124b614d3db11b67b1b40cb342: Deleting log segment in path: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515622168709-19292-0/minicluster-data/ts-0-root/wals/f9bf63ed0fcd43989b28e75e9ae5ab36/wal-000000008 (ops 37-41)
I20260812 06:20:24.029261 19412 log.cc:1079] T f9bf63ed0fcd43989b28e75e9ae5ab36 P e270a6124b614d3db11b67b1b40cb342: Deleting log segment in path: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515622168709-19292-0/minicluster-data/ts-0-root/wals/f9bf63ed0fcd43989b28e75e9ae5ab36/wal-000000009 (ops 42-46)
I20260812 06:20:24.029290 19412 log.cc:1079] T f9bf63ed0fcd43989b28e75e9ae5ab36 P e270a6124b614d3db11b67b1b40cb342: Deleting log segment in path: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515622168709-19292-0/minicluster-data/ts-0-root/wals/f9bf63ed0fcd43989b28e75e9ae5ab36/wal-000000010 (ops 47-51)
I20260812 06:20:24.029317 19412 log.cc:1079] T f9bf63ed0fcd43989b28e75e9ae5ab36 P e270a6124b614d3db11b67b1b40cb342: Deleting log segment in path: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515622168709-19292-0/minicluster-data/ts-0-root/wals/f9bf63ed0fcd43989b28e75e9ae5ab36/wal-000000011 (ops 52-56)
I20260812 06:20:24.029346 19412 log.cc:1079] T f9bf63ed0fcd43989b28e75e9ae5ab36 P e270a6124b614d3db11b67b1b40cb342: Deleting log segment in path: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515622168709-19292-0/minicluster-data/ts-0-root/wals/f9bf63ed0fcd43989b28e75e9ae5ab36/wal-000000012 (ops 57-61)
I20260812 06:20:24.029378 19412 log.cc:1079] T f9bf63ed0fcd43989b28e75e9ae5ab36 P e270a6124b614d3db11b67b1b40cb342: Deleting log segment in path: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515622168709-19292-0/minicluster-data/ts-0-root/wals/f9bf63ed0fcd43989b28e75e9ae5ab36/wal-000000013 (ops 62-66)
I20260812 06:20:24.029407 19412 log.cc:1079] T f9bf63ed0fcd43989b28e75e9ae5ab36 P e270a6124b614d3db11b67b1b40cb342: Deleting log segment in path: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515622168709-19292-0/minicluster-data/ts-0-root/wals/f9bf63ed0fcd43989b28e75e9ae5ab36/wal-000000014 (ops 67-71)
I20260812 06:20:24.054934 19412 maintenance_manager.cc:643] P e270a6124b614d3db11b67b1b40cb342: LogGCOp(f9bf63ed0fcd43989b28e75e9ae5ab36) complete. Timing: real 0.026s	user 0.001s	sys 0.023s Metrics: {}
I20260812 06:20:24.055472 19481 maintenance_manager.cc:419] P e270a6124b614d3db11b67b1b40cb342: Scheduling UndoDeltaBlockGCOp(f9bf63ed0fcd43989b28e75e9ae5ab36): 472 bytes on disk
I20260812 06:20:24.055902 19412 maintenance_manager.cc:643] P e270a6124b614d3db11b67b1b40cb342: UndoDeltaBlockGCOp(f9bf63ed0fcd43989b28e75e9ae5ab36) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4,"spinlock_wait_cycles":768}
I20260812 06:20:24.056373 19481 maintenance_manager.cc:419] P e270a6124b614d3db11b67b1b40cb342: Scheduling FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36): perf score=2.188937
I20260812 06:20:24.070840 19412 maintenance_manager.cc:643] P e270a6124b614d3db11b67b1b40cb342: FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36) complete. Timing: real 0.014s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3897,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:24.071260 19481 maintenance_manager.cc:419] P e270a6124b614d3db11b67b1b40cb342: Scheduling FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36): perf score=2.188937
I20260812 06:20:24.089243 19412 maintenance_manager.cc:643] P e270a6124b614d3db11b67b1b40cb342: FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36) complete. Timing: real 0.018s	user 0.003s	sys 0.015s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3673,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:24.089948 19481 maintenance_manager.cc:419] P e270a6124b614d3db11b67b1b40cb342: Scheduling MajorDeltaCompactionOp(f9bf63ed0fcd43989b28e75e9ae5ab36): perf score=1.000000
I20260812 06:20:24.281201 19412 maintenance_manager.cc:643] P e270a6124b614d3db11b67b1b40cb342: MajorDeltaCompactionOp(f9bf63ed0fcd43989b28e75e9ae5ab36) complete. Timing: real 0.191s	user 0.110s	sys 0.073s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28918333,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":764,"lbm_read_time_us":13207,"lbm_reads_lt_1ms":674,"lbm_write_time_us":32335,"lbm_writes_lt_1ms":643,"mutex_wait_us":41,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":10496,"thread_start_us":75,"threads_started":1,"update_count":3000}
I20260812 06:20:24.281769 19481 maintenance_manager.cc:419] P e270a6124b614d3db11b67b1b40cb342: Scheduling FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36): perf score=14.095187
I20260812 06:20:24.335824 19412 maintenance_manager.cc:643] P e270a6124b614d3db11b67b1b40cb342: FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36) complete. Timing: real 0.052s	user 0.017s	sys 0.033s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18178,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:24.336369 19481 maintenance_manager.cc:419] P e270a6124b614d3db11b67b1b40cb342: Scheduling FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36): perf score=2.188937
I20260812 06:20:24.346684 19412 maintenance_manager.cc:643] P e270a6124b614d3db11b67b1b40cb342: FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3813,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:24.347106 19481 maintenance_manager.cc:419] P e270a6124b614d3db11b67b1b40cb342: Scheduling MajorDeltaCompactionOp(f9bf63ed0fcd43989b28e75e9ae5ab36): perf score=1.000000
I20260812 06:20:24.506968 19412 maintenance_manager.cc:643] P e270a6124b614d3db11b67b1b40cb342: MajorDeltaCompactionOp(f9bf63ed0fcd43989b28e75e9ae5ab36) complete. Timing: real 0.160s	user 0.097s	sys 0.062s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":717,"lbm_read_time_us":11249,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27325,"lbm_writes_lt_1ms":543,"mutex_wait_us":237,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:20:24.509812 19481 maintenance_manager.cc:419] P e270a6124b614d3db11b67b1b40cb342: Scheduling FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36): perf score=10.126437
I20260812 06:20:24.549547 19412 maintenance_manager.cc:643] P e270a6124b614d3db11b67b1b40cb342: FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36) complete. Timing: real 0.039s	user 0.022s	sys 0.017s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16085,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:20:24.550256 19481 maintenance_manager.cc:419] P e270a6124b614d3db11b67b1b40cb342: Scheduling FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36): perf score=2.188937
I20260812 06:20:24.563340 19412 maintenance_manager.cc:643] P e270a6124b614d3db11b67b1b40cb342: FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36) complete. Timing: real 0.013s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4412,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:24.563822 19481 maintenance_manager.cc:419] P e270a6124b614d3db11b67b1b40cb342: Scheduling MajorDeltaCompactionOp(f9bf63ed0fcd43989b28e75e9ae5ab36): perf score=1.000000
I20260812 06:20:24.691571 19412 maintenance_manager.cc:643] P e270a6124b614d3db11b67b1b40cb342: MajorDeltaCompactionOp(f9bf63ed0fcd43989b28e75e9ae5ab36) complete. Timing: real 0.128s	user 0.111s	sys 0.016s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":907,"lbm_read_time_us":8403,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23807,"lbm_writes_lt_1ms":443,"mutex_wait_us":278,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":36096,"update_count":2000}
I20260812 06:20:24.694525 19481 maintenance_manager.cc:419] P e270a6124b614d3db11b67b1b40cb342: Scheduling FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36): perf score=10.126437
I20260812 06:20:24.727105 19412 maintenance_manager.cc:643] P e270a6124b614d3db11b67b1b40cb342: FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36) complete. Timing: real 0.032s	user 0.030s	sys 0.000s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":13379,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:24.727736 19481 maintenance_manager.cc:419] P e270a6124b614d3db11b67b1b40cb342: Scheduling FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36): perf score=2.188937
I20260812 06:20:24.743777 19412 maintenance_manager.cc:643] P e270a6124b614d3db11b67b1b40cb342: FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36) complete. Timing: real 0.016s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6291,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:24.744252 19481 maintenance_manager.cc:419] P e270a6124b614d3db11b67b1b40cb342: Scheduling MajorDeltaCompactionOp(f9bf63ed0fcd43989b28e75e9ae5ab36): perf score=1.000000
I20260812 06:20:24.862044 19412 maintenance_manager.cc:643] P e270a6124b614d3db11b67b1b40cb342: MajorDeltaCompactionOp(f9bf63ed0fcd43989b28e75e9ae5ab36) complete. Timing: real 0.118s	user 0.106s	sys 0.011s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713275,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":315,"lbm_read_time_us":7352,"lbm_reads_lt_1ms":468,"lbm_write_time_us":23128,"lbm_writes_lt_1ms":443,"mutex_wait_us":39,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2000}
I20260812 06:20:24.862694 19481 maintenance_manager.cc:419] P e270a6124b614d3db11b67b1b40cb342: Scheduling FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36): perf score=10.126437
I20260812 06:20:24.906297 19412 maintenance_manager.cc:643] P e270a6124b614d3db11b67b1b40cb342: FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36) complete. Timing: real 0.043s	user 0.022s	sys 0.009s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":13545,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:24.906872 19481 maintenance_manager.cc:419] P e270a6124b614d3db11b67b1b40cb342: Scheduling FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36): perf score=2.188937
I20260812 06:20:24.916880 19412 maintenance_manager.cc:643] P e270a6124b614d3db11b67b1b40cb342: FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3554,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:24.917510 19481 maintenance_manager.cc:419] P e270a6124b614d3db11b67b1b40cb342: Scheduling MajorDeltaCompactionOp(f9bf63ed0fcd43989b28e75e9ae5ab36): perf score=1.000000
I20260812 06:20:25.038100 19412 maintenance_manager.cc:643] P e270a6124b614d3db11b67b1b40cb342: MajorDeltaCompactionOp(f9bf63ed0fcd43989b28e75e9ae5ab36) complete. Timing: real 0.120s	user 0.084s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713273,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":251,"lbm_read_time_us":9670,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21005,"lbm_writes_lt_1ms":443,"mutex_wait_us":26,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":13824,"update_count":2000}
I20260812 06:20:25.038781 19481 maintenance_manager.cc:419] P e270a6124b614d3db11b67b1b40cb342: Scheduling FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36): perf score=10.126437
I20260812 06:20:25.081557 19412 maintenance_manager.cc:643] P e270a6124b614d3db11b67b1b40cb342: FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36) complete. Timing: real 0.042s	user 0.020s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13543,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:25.082101 19481 maintenance_manager.cc:419] P e270a6124b614d3db11b67b1b40cb342: Scheduling FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36): perf score=2.188937
I20260812 06:20:25.092038 19412 maintenance_manager.cc:643] P e270a6124b614d3db11b67b1b40cb342: FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36) complete. Timing: real 0.010s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3817,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:25.092442 19481 maintenance_manager.cc:419] P e270a6124b614d3db11b67b1b40cb342: Scheduling MajorDeltaCompactionOp(f9bf63ed0fcd43989b28e75e9ae5ab36): perf score=1.000000
I20260812 06:20:25.223251 19412 maintenance_manager.cc:643] P e270a6124b614d3db11b67b1b40cb342: MajorDeltaCompactionOp(f9bf63ed0fcd43989b28e75e9ae5ab36) complete. Timing: real 0.131s	user 0.086s	sys 0.044s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":322,"lbm_read_time_us":9881,"lbm_reads_lt_1ms":472,"lbm_write_time_us":20384,"lbm_writes_lt_1ms":443,"mutex_wait_us":28,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11520,"update_count":2000}
I20260812 06:20:25.223846 19481 maintenance_manager.cc:419] P e270a6124b614d3db11b67b1b40cb342: Scheduling FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36): perf score=10.126437
I20260812 06:20:25.268177 19412 maintenance_manager.cc:643] P e270a6124b614d3db11b67b1b40cb342: FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36) complete. Timing: real 0.044s	user 0.023s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14795,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:25.268684 19481 maintenance_manager.cc:419] P e270a6124b614d3db11b67b1b40cb342: Scheduling FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36): perf score=2.188937
I20260812 06:20:25.278338 19412 maintenance_manager.cc:643] P e270a6124b614d3db11b67b1b40cb342: FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36) complete. Timing: real 0.009s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3510,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:25.278782 19481 maintenance_manager.cc:419] P e270a6124b614d3db11b67b1b40cb342: Scheduling MajorDeltaCompactionOp(f9bf63ed0fcd43989b28e75e9ae5ab36): perf score=1.000000
I20260812 06:20:25.394480 19412 maintenance_manager.cc:643] P e270a6124b614d3db11b67b1b40cb342: MajorDeltaCompactionOp(f9bf63ed0fcd43989b28e75e9ae5ab36) complete. Timing: real 0.116s	user 0.100s	sys 0.015s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713271,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":251,"lbm_read_time_us":8151,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21443,"lbm_writes_lt_1ms":443,"mutex_wait_us":23,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8192,"update_count":2000}
I20260812 06:20:25.395078 19481 maintenance_manager.cc:419] P e270a6124b614d3db11b67b1b40cb342: Scheduling FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36): perf score=10.126437
I20260812 06:20:25.439246 19412 maintenance_manager.cc:643] P e270a6124b614d3db11b67b1b40cb342: FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36) complete. Timing: real 0.044s	user 0.030s	sys 0.004s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15419,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:25.439772 19481 maintenance_manager.cc:419] P e270a6124b614d3db11b67b1b40cb342: Scheduling FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36): perf score=2.188937
I20260812 06:20:25.450314 19412 maintenance_manager.cc:643] P e270a6124b614d3db11b67b1b40cb342: FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3970,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:25.450877 19481 maintenance_manager.cc:419] P e270a6124b614d3db11b67b1b40cb342: Scheduling FlushMRSOp(f9bf63ed0fcd43989b28e75e9ae5ab36): perf score=1.000000
I20260812 06:20:25.479707 19412 maintenance_manager.cc:643] P e270a6124b614d3db11b67b1b40cb342: FlushMRSOp(f9bf63ed0fcd43989b28e75e9ae5ab36) complete. Timing: real 0.029s	user 0.024s	sys 0.003s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":47,"dirs.run_cpu_time_us":157,"dirs.run_wall_time_us":1348,"drs_written":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1788,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:20:25.480435 19481 maintenance_manager.cc:419] P e270a6124b614d3db11b67b1b40cb342: Scheduling LogGCOp(f9bf63ed0fcd43989b28e75e9ae5ab36): free 124710258 bytes of WAL
I20260812 06:20:25.480675 19412 log_reader.cc:385] T f9bf63ed0fcd43989b28e75e9ae5ab36: removed 12 log segments from log reader
I20260812 06:20:25.480732 19412 log.cc:1079] T f9bf63ed0fcd43989b28e75e9ae5ab36 P e270a6124b614d3db11b67b1b40cb342: Deleting log segment in path: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515622168709-19292-0/minicluster-data/ts-0-root/wals/f9bf63ed0fcd43989b28e75e9ae5ab36/wal-000000015 (ops 72-76)
I20260812 06:20:25.480778 19412 log.cc:1079] T f9bf63ed0fcd43989b28e75e9ae5ab36 P e270a6124b614d3db11b67b1b40cb342: Deleting log segment in path: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515622168709-19292-0/minicluster-data/ts-0-root/wals/f9bf63ed0fcd43989b28e75e9ae5ab36/wal-000000016 (ops 77-81)
I20260812 06:20:25.480811 19412 log.cc:1079] T f9bf63ed0fcd43989b28e75e9ae5ab36 P e270a6124b614d3db11b67b1b40cb342: Deleting log segment in path: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515622168709-19292-0/minicluster-data/ts-0-root/wals/f9bf63ed0fcd43989b28e75e9ae5ab36/wal-000000017 (ops 82-86)
I20260812 06:20:25.480834 19412 log.cc:1079] T f9bf63ed0fcd43989b28e75e9ae5ab36 P e270a6124b614d3db11b67b1b40cb342: Deleting log segment in path: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515622168709-19292-0/minicluster-data/ts-0-root/wals/f9bf63ed0fcd43989b28e75e9ae5ab36/wal-000000018 (ops 87-91)
I20260812 06:20:25.480854 19412 log.cc:1079] T f9bf63ed0fcd43989b28e75e9ae5ab36 P e270a6124b614d3db11b67b1b40cb342: Deleting log segment in path: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515622168709-19292-0/minicluster-data/ts-0-root/wals/f9bf63ed0fcd43989b28e75e9ae5ab36/wal-000000019 (ops 92-96)
I20260812 06:20:25.480883 19412 log.cc:1079] T f9bf63ed0fcd43989b28e75e9ae5ab36 P e270a6124b614d3db11b67b1b40cb342: Deleting log segment in path: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515622168709-19292-0/minicluster-data/ts-0-root/wals/f9bf63ed0fcd43989b28e75e9ae5ab36/wal-000000020 (ops 97-101)
I20260812 06:20:25.480916 19412 log.cc:1079] T f9bf63ed0fcd43989b28e75e9ae5ab36 P e270a6124b614d3db11b67b1b40cb342: Deleting log segment in path: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515622168709-19292-0/minicluster-data/ts-0-root/wals/f9bf63ed0fcd43989b28e75e9ae5ab36/wal-000000021 (ops 102-106)
I20260812 06:20:25.480945 19412 log.cc:1079] T f9bf63ed0fcd43989b28e75e9ae5ab36 P e270a6124b614d3db11b67b1b40cb342: Deleting log segment in path: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515622168709-19292-0/minicluster-data/ts-0-root/wals/f9bf63ed0fcd43989b28e75e9ae5ab36/wal-000000022 (ops 107-111)
I20260812 06:20:25.480975 19412 log.cc:1079] T f9bf63ed0fcd43989b28e75e9ae5ab36 P e270a6124b614d3db11b67b1b40cb342: Deleting log segment in path: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515622168709-19292-0/minicluster-data/ts-0-root/wals/f9bf63ed0fcd43989b28e75e9ae5ab36/wal-000000023 (ops 112-116)
I20260812 06:20:25.481002 19412 log.cc:1079] T f9bf63ed0fcd43989b28e75e9ae5ab36 P e270a6124b614d3db11b67b1b40cb342: Deleting log segment in path: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515622168709-19292-0/minicluster-data/ts-0-root/wals/f9bf63ed0fcd43989b28e75e9ae5ab36/wal-000000024 (ops 117-121)
I20260812 06:20:25.481031 19412 log.cc:1079] T f9bf63ed0fcd43989b28e75e9ae5ab36 P e270a6124b614d3db11b67b1b40cb342: Deleting log segment in path: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515622168709-19292-0/minicluster-data/ts-0-root/wals/f9bf63ed0fcd43989b28e75e9ae5ab36/wal-000000025 (ops 122-126)
I20260812 06:20:25.481062 19412 log.cc:1079] T f9bf63ed0fcd43989b28e75e9ae5ab36 P e270a6124b614d3db11b67b1b40cb342: Deleting log segment in path: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515622168709-19292-0/minicluster-data/ts-0-root/wals/f9bf63ed0fcd43989b28e75e9ae5ab36/wal-000000026 (ops 127-131)
I20260812 06:20:25.506142 19412 maintenance_manager.cc:643] P e270a6124b614d3db11b67b1b40cb342: LogGCOp(f9bf63ed0fcd43989b28e75e9ae5ab36) complete. Timing: real 0.026s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:20:25.506534 19481 maintenance_manager.cc:419] P e270a6124b614d3db11b67b1b40cb342: Scheduling UndoDeltaBlockGCOp(f9bf63ed0fcd43989b28e75e9ae5ab36): 482 bytes on disk
I20260812 06:20:25.506961 19412 maintenance_manager.cc:643] P e270a6124b614d3db11b67b1b40cb342: UndoDeltaBlockGCOp(f9bf63ed0fcd43989b28e75e9ae5ab36) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4}
I20260812 06:20:25.507496 19481 maintenance_manager.cc:419] P e270a6124b614d3db11b67b1b40cb342: Scheduling FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36): perf score=3.181125
I20260812 06:20:25.518797 19412 maintenance_manager.cc:643] P e270a6124b614d3db11b67b1b40cb342: FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36) complete. Timing: real 0.011s	user 0.008s	sys 0.002s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4006,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:25.519209 19481 maintenance_manager.cc:419] P e270a6124b614d3db11b67b1b40cb342: Scheduling FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36): perf score=2.188937
I20260812 06:20:25.532094 19412 maintenance_manager.cc:643] P e270a6124b614d3db11b67b1b40cb342: FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36) complete. Timing: real 0.013s	user 0.000s	sys 0.011s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5101,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:25.532562 19481 maintenance_manager.cc:419] P e270a6124b614d3db11b67b1b40cb342: Scheduling MajorDeltaCompactionOp(f9bf63ed0fcd43989b28e75e9ae5ab36): perf score=1.000000
I20260812 06:20:25.696204 19412 maintenance_manager.cc:643] P e270a6124b614d3db11b67b1b40cb342: MajorDeltaCompactionOp(f9bf63ed0fcd43989b28e75e9ae5ab36) complete. Timing: real 0.163s	user 0.138s	sys 0.019s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28918322,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":527,"lbm_read_time_us":11005,"lbm_reads_lt_1ms":674,"lbm_write_time_us":30758,"lbm_writes_lt_1ms":643,"mutex_wait_us":59,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":14208,"thread_start_us":78,"threads_started":1,"update_count":3000}
I20260812 06:20:25.696746 19481 maintenance_manager.cc:419] P e270a6124b614d3db11b67b1b40cb342: Scheduling FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36): perf score=14.095187
I20260812 06:20:25.744165 19412 maintenance_manager.cc:643] P e270a6124b614d3db11b67b1b40cb342: FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36) complete. Timing: real 0.047s	user 0.029s	sys 0.015s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20913,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:25.744661 19481 maintenance_manager.cc:419] P e270a6124b614d3db11b67b1b40cb342: Scheduling FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36): perf score=2.188937
I20260812 06:20:25.760452 19412 maintenance_manager.cc:643] P e270a6124b614d3db11b67b1b40cb342: FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36) complete. Timing: real 0.016s	user 0.011s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6030,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:25.761044 19481 maintenance_manager.cc:419] P e270a6124b614d3db11b67b1b40cb342: Scheduling MajorDeltaCompactionOp(f9bf63ed0fcd43989b28e75e9ae5ab36): perf score=1.000000
I20260812 06:20:25.914896 19412 maintenance_manager.cc:643] P e270a6124b614d3db11b67b1b40cb342: MajorDeltaCompactionOp(f9bf63ed0fcd43989b28e75e9ae5ab36) complete. Timing: real 0.154s	user 0.099s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815685,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":746,"lbm_read_time_us":9244,"lbm_reads_lt_1ms":564,"lbm_write_time_us":27194,"lbm_writes_lt_1ms":543,"mutex_wait_us":71,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3840,"update_count":2500}
I20260812 06:20:25.915560 19481 maintenance_manager.cc:419] P e270a6124b614d3db11b67b1b40cb342: Scheduling FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36): perf score=14.095187
I20260812 06:20:25.965524 19412 maintenance_manager.cc:643] P e270a6124b614d3db11b67b1b40cb342: FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36) complete. Timing: real 0.050s	user 0.030s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22047,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:25.966145 19481 maintenance_manager.cc:419] P e270a6124b614d3db11b67b1b40cb342: Scheduling MajorDeltaCompactionOp(f9bf63ed0fcd43989b28e75e9ae5ab36): perf score=1.000000
I20260812 06:20:26.110649 19412 maintenance_manager.cc:643] P e270a6124b614d3db11b67b1b40cb342: MajorDeltaCompactionOp(f9bf63ed0fcd43989b28e75e9ae5ab36) complete. Timing: real 0.144s	user 0.107s	sys 0.032s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713153,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":174,"lbm_read_time_us":9251,"lbm_reads_lt_1ms":467,"lbm_write_time_us":22624,"lbm_writes_lt_1ms":443,"mutex_wait_us":48,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":53632,"update_count":2000}
I20260812 06:20:26.111289 19481 maintenance_manager.cc:419] P e270a6124b614d3db11b67b1b40cb342: Scheduling FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36): perf score=11.118625
I20260812 06:20:26.143594 19412 maintenance_manager.cc:643] P e270a6124b614d3db11b67b1b40cb342: FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36) complete. Timing: real 0.032s	user 0.020s	sys 0.012s Metrics: {"bytes_written":12717738,"delete_count":0,"lbm_write_time_us":11880,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:26.144241 19481 maintenance_manager.cc:419] P e270a6124b614d3db11b67b1b40cb342: Scheduling FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36): perf score=2.188937
I20260812 06:20:26.165719 19412 maintenance_manager.cc:643] P e270a6124b614d3db11b67b1b40cb342: FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36) complete. Timing: real 0.021s	user 0.004s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4011,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:26.166263 19481 maintenance_manager.cc:419] P e270a6124b614d3db11b67b1b40cb342: Scheduling FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36): perf score=2.188937
I20260812 06:20:26.180999 19412 maintenance_manager.cc:643] P e270a6124b614d3db11b67b1b40cb342: FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36) complete. Timing: real 0.015s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5260,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:26.181600 19481 maintenance_manager.cc:419] P e270a6124b614d3db11b67b1b40cb342: Scheduling MajorDeltaCompactionOp(f9bf63ed0fcd43989b28e75e9ae5ab36): perf score=1.000000
I20260812 06:20:26.361301 19412 maintenance_manager.cc:643] P e270a6124b614d3db11b67b1b40cb342: MajorDeltaCompactionOp(f9bf63ed0fcd43989b28e75e9ae5ab36) complete. Timing: real 0.179s	user 0.106s	sys 0.059s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815797,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":663,"lbm_read_time_us":9351,"lbm_reads_lt_1ms":573,"lbm_write_time_us":29231,"lbm_writes_lt_1ms":543,"mutex_wait_us":37,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:20:26.362082 19481 maintenance_manager.cc:419] P e270a6124b614d3db11b67b1b40cb342: Scheduling FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36): perf score=14.095187
I20260812 06:20:26.409581 19412 maintenance_manager.cc:643] P e270a6124b614d3db11b67b1b40cb342: FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36) complete. Timing: real 0.047s	user 0.028s	sys 0.012s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":16969,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:26.410149 19481 maintenance_manager.cc:419] P e270a6124b614d3db11b67b1b40cb342: Scheduling FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36): perf score=2.188937
I20260812 06:20:26.425899 19412 maintenance_manager.cc:643] P e270a6124b614d3db11b67b1b40cb342: FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36) complete. Timing: real 0.016s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5664,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:26.426559 19481 maintenance_manager.cc:419] P e270a6124b614d3db11b67b1b40cb342: Scheduling MajorDeltaCompactionOp(f9bf63ed0fcd43989b28e75e9ae5ab36): perf score=1.000000
I20260812 06:20:26.580065 19412 maintenance_manager.cc:643] P e270a6124b614d3db11b67b1b40cb342: MajorDeltaCompactionOp(f9bf63ed0fcd43989b28e75e9ae5ab36) complete. Timing: real 0.153s	user 0.118s	sys 0.029s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":648,"lbm_read_time_us":10690,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29643,"lbm_writes_lt_1ms":543,"mutex_wait_us":260,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2500}
I20260812 06:20:26.580602 19481 maintenance_manager.cc:419] P e270a6124b614d3db11b67b1b40cb342: Scheduling FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36): perf score=11.118625
I20260812 06:20:26.616513 19412 maintenance_manager.cc:643] P e270a6124b614d3db11b67b1b40cb342: FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36) complete. Timing: real 0.036s	user 0.007s	sys 0.025s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":14633,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:26.617162 19481 maintenance_manager.cc:419] P e270a6124b614d3db11b67b1b40cb342: Scheduling FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36): perf score=2.188937
I20260812 06:20:26.631439 19412 maintenance_manager.cc:643] P e270a6124b614d3db11b67b1b40cb342: FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36) complete. Timing: real 0.014s	user 0.001s	sys 0.009s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5064,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:26.632040 19481 maintenance_manager.cc:419] P e270a6124b614d3db11b67b1b40cb342: Scheduling MajorDeltaCompactionOp(f9bf63ed0fcd43989b28e75e9ae5ab36): perf score=1.000000
I20260812 06:20:26.749979 19412 maintenance_manager.cc:643] P e270a6124b614d3db11b67b1b40cb342: MajorDeltaCompactionOp(f9bf63ed0fcd43989b28e75e9ae5ab36) complete. Timing: real 0.118s	user 0.098s	sys 0.019s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713264,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":726,"lbm_read_time_us":7822,"lbm_reads_lt_1ms":464,"lbm_write_time_us":21017,"lbm_writes_lt_1ms":443,"mutex_wait_us":275,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3456,"update_count":2000}
I20260812 06:20:26.750509 19481 maintenance_manager.cc:419] P e270a6124b614d3db11b67b1b40cb342: Scheduling FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36): perf score=10.126437
I20260812 06:20:26.788379 19412 maintenance_manager.cc:643] P e270a6124b614d3db11b67b1b40cb342: FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36) complete. Timing: real 0.038s	user 0.016s	sys 0.016s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":14786,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:26.789018 19481 maintenance_manager.cc:419] P e270a6124b614d3db11b67b1b40cb342: Scheduling FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36): perf score=2.188937
I20260812 06:20:26.798674 19412 maintenance_manager.cc:643] P e270a6124b614d3db11b67b1b40cb342: FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36) complete. Timing: real 0.009s	user 0.003s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3423,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:26.799237 19481 maintenance_manager.cc:419] P e270a6124b614d3db11b67b1b40cb342: Scheduling FlushMRSOp(f9bf63ed0fcd43989b28e75e9ae5ab36): perf score=1.000000
I20260812 06:20:26.826700 19412 maintenance_manager.cc:643] P e270a6124b614d3db11b67b1b40cb342: FlushMRSOp(f9bf63ed0fcd43989b28e75e9ae5ab36) complete. Timing: real 0.027s	user 0.020s	sys 0.006s Metrics: {"bytes_written":1193507,"cfile_init":1,"dirs.queue_time_us":59,"dirs.run_cpu_time_us":201,"dirs.run_wall_time_us":1348,"drs_written":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1526,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:20:26.827476 19481 maintenance_manager.cc:419] P e270a6124b614d3db11b67b1b40cb342: Scheduling LogGCOp(f9bf63ed0fcd43989b28e75e9ae5ab36): free 121006749 bytes of WAL
I20260812 06:20:26.827742 19412 log_reader.cc:385] T f9bf63ed0fcd43989b28e75e9ae5ab36: removed 12 log segments from log reader
I20260812 06:20:26.827795 19412 log.cc:1079] T f9bf63ed0fcd43989b28e75e9ae5ab36 P e270a6124b614d3db11b67b1b40cb342: Deleting log segment in path: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515622168709-19292-0/minicluster-data/ts-0-root/wals/f9bf63ed0fcd43989b28e75e9ae5ab36/wal-000000027 (ops 132-136)
I20260812 06:20:26.827834 19412 log.cc:1079] T f9bf63ed0fcd43989b28e75e9ae5ab36 P e270a6124b614d3db11b67b1b40cb342: Deleting log segment in path: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515622168709-19292-0/minicluster-data/ts-0-root/wals/f9bf63ed0fcd43989b28e75e9ae5ab36/wal-000000028 (ops 137-141)
I20260812 06:20:26.827872 19412 log.cc:1079] T f9bf63ed0fcd43989b28e75e9ae5ab36 P e270a6124b614d3db11b67b1b40cb342: Deleting log segment in path: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515622168709-19292-0/minicluster-data/ts-0-root/wals/f9bf63ed0fcd43989b28e75e9ae5ab36/wal-000000029 (ops 142-146)
I20260812 06:20:26.827898 19412 log.cc:1079] T f9bf63ed0fcd43989b28e75e9ae5ab36 P e270a6124b614d3db11b67b1b40cb342: Deleting log segment in path: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515622168709-19292-0/minicluster-data/ts-0-root/wals/f9bf63ed0fcd43989b28e75e9ae5ab36/wal-000000030 (ops 147-151)
I20260812 06:20:26.827950 19412 log.cc:1079] T f9bf63ed0fcd43989b28e75e9ae5ab36 P e270a6124b614d3db11b67b1b40cb342: Deleting log segment in path: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515622168709-19292-0/minicluster-data/ts-0-root/wals/f9bf63ed0fcd43989b28e75e9ae5ab36/wal-000000031 (ops 152-156)
I20260812 06:20:26.827976 19412 log.cc:1079] T f9bf63ed0fcd43989b28e75e9ae5ab36 P e270a6124b614d3db11b67b1b40cb342: Deleting log segment in path: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515622168709-19292-0/minicluster-data/ts-0-root/wals/f9bf63ed0fcd43989b28e75e9ae5ab36/wal-000000032 (ops 157-160)
I20260812 06:20:26.828007 19412 log.cc:1079] T f9bf63ed0fcd43989b28e75e9ae5ab36 P e270a6124b614d3db11b67b1b40cb342: Deleting log segment in path: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515622168709-19292-0/minicluster-data/ts-0-root/wals/f9bf63ed0fcd43989b28e75e9ae5ab36/wal-000000033 (ops 161-165)
I20260812 06:20:26.828037 19412 log.cc:1079] T f9bf63ed0fcd43989b28e75e9ae5ab36 P e270a6124b614d3db11b67b1b40cb342: Deleting log segment in path: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515622168709-19292-0/minicluster-data/ts-0-root/wals/f9bf63ed0fcd43989b28e75e9ae5ab36/wal-000000034 (ops 166-170)
I20260812 06:20:26.828068 19412 log.cc:1079] T f9bf63ed0fcd43989b28e75e9ae5ab36 P e270a6124b614d3db11b67b1b40cb342: Deleting log segment in path: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515622168709-19292-0/minicluster-data/ts-0-root/wals/f9bf63ed0fcd43989b28e75e9ae5ab36/wal-000000035 (ops 171-175)
I20260812 06:20:26.828099 19412 log.cc:1079] T f9bf63ed0fcd43989b28e75e9ae5ab36 P e270a6124b614d3db11b67b1b40cb342: Deleting log segment in path: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515622168709-19292-0/minicluster-data/ts-0-root/wals/f9bf63ed0fcd43989b28e75e9ae5ab36/wal-000000036 (ops 176-180)
I20260812 06:20:26.828130 19412 log.cc:1079] T f9bf63ed0fcd43989b28e75e9ae5ab36 P e270a6124b614d3db11b67b1b40cb342: Deleting log segment in path: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515622168709-19292-0/minicluster-data/ts-0-root/wals/f9bf63ed0fcd43989b28e75e9ae5ab36/wal-000000037 (ops 181-185)
I20260812 06:20:26.828161 19412 log.cc:1079] T f9bf63ed0fcd43989b28e75e9ae5ab36 P e270a6124b614d3db11b67b1b40cb342: Deleting log segment in path: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515622168709-19292-0/minicluster-data/ts-0-root/wals/f9bf63ed0fcd43989b28e75e9ae5ab36/wal-000000038 (ops 186-190)
I20260812 06:20:26.851975 19412 maintenance_manager.cc:643] P e270a6124b614d3db11b67b1b40cb342: LogGCOp(f9bf63ed0fcd43989b28e75e9ae5ab36) complete. Timing: real 0.024s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:20:26.852459 19481 maintenance_manager.cc:419] P e270a6124b614d3db11b67b1b40cb342: Scheduling FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36): perf score=3.181125
I20260812 06:20:26.872267 19412 maintenance_manager.cc:643] P e270a6124b614d3db11b67b1b40cb342: FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36) complete. Timing: real 0.020s	user 0.008s	sys 0.008s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":7316,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:26.872730 19481 maintenance_manager.cc:419] P e270a6124b614d3db11b67b1b40cb342: Scheduling UndoDeltaBlockGCOp(f9bf63ed0fcd43989b28e75e9ae5ab36): 463 bytes on disk
I20260812 06:20:26.873127 19412 maintenance_manager.cc:643] P e270a6124b614d3db11b67b1b40cb342: UndoDeltaBlockGCOp(f9bf63ed0fcd43989b28e75e9ae5ab36) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":51,"lbm_reads_lt_1ms":4}
I20260812 06:20:26.873692 19481 maintenance_manager.cc:419] P e270a6124b614d3db11b67b1b40cb342: Scheduling FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36): perf score=2.188937
I20260812 06:20:26.883211 19412 maintenance_manager.cc:643] P e270a6124b614d3db11b67b1b40cb342: FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3569,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:26.883651 19481 maintenance_manager.cc:419] P e270a6124b614d3db11b67b1b40cb342: Scheduling MajorDeltaCompactionOp(f9bf63ed0fcd43989b28e75e9ae5ab36): perf score=1.000000
I20260812 06:20:27.009986 19292 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.556s	user 1.693s	sys 0.145s
I20260812 06:20:27.045215 19412 maintenance_manager.cc:643] P e270a6124b614d3db11b67b1b40cb342: MajorDeltaCompactionOp(f9bf63ed0fcd43989b28e75e9ae5ab36) complete. Timing: real 0.161s	user 0.131s	sys 0.026s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28918321,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"lbm_read_time_us":12131,"lbm_reads_lt_1ms":670,"lbm_write_time_us":33972,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":642,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2816,"update_count":3000}
I20260812 06:20:27.045719 19481 maintenance_manager.cc:419] P e270a6124b614d3db11b67b1b40cb342: Scheduling FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36): perf score=10.126437
I20260812 06:20:27.074045 19412 maintenance_manager.cc:643] P e270a6124b614d3db11b67b1b40cb342: FlushDeltaMemStoresOp(f9bf63ed0fcd43989b28e75e9ae5ab36) complete. Timing: real 0.028s	user 0.014s	sys 0.013s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":11430,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:27.074579 19481 maintenance_manager.cc:419] P e270a6124b614d3db11b67b1b40cb342: Scheduling MajorDeltaCompactionOp(f9bf63ed0fcd43989b28e75e9ae5ab36): perf score=1.000000
I20260812 06:20:27.076013 19292 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.065s	user 0.001s	sys 0.000s
I20260812 06:20:27.076603 19292 tablet_server.cc:179] TabletServer@127.18.215.1:0 shutting down...
I20260812 06:20:27.160615 19412 maintenance_manager.cc:643] P e270a6124b614d3db11b67b1b40cb342: MajorDeltaCompactionOp(f9bf63ed0fcd43989b28e75e9ae5ab36) complete. Timing: real 0.086s	user 0.069s	sys 0.016s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16610740,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":635,"lbm_read_time_us":5969,"lbm_reads_lt_1ms":367,"lbm_write_time_us":16327,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":342,"mutex_wait_us":297,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":12032,"update_count":1500}
I20260812 06:20:27.161249 19292 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:27.161677 19292 tablet_replica.cc:333] T f9bf63ed0fcd43989b28e75e9ae5ab36 P e270a6124b614d3db11b67b1b40cb342: stopping tablet replica
I20260812 06:20:27.161926 19292 raft_consensus.cc:2243] T f9bf63ed0fcd43989b28e75e9ae5ab36 P e270a6124b614d3db11b67b1b40cb342 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:27.162151 19292 raft_consensus.cc:2272] T f9bf63ed0fcd43989b28e75e9ae5ab36 P e270a6124b614d3db11b67b1b40cb342 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:27.177356 19292 tablet_server.cc:196] TabletServer@127.18.215.1:0 shutdown complete.
I20260812 06:20:27.192766 19292 master.cc:562] Master@127.18.215.62:45791 shutting down...
I20260812 06:20:27.196077 19292 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 554617fdcd4d46f48555ab345aceb015 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:27.196246 19292 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 554617fdcd4d46f48555ab345aceb015 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:27.196321 19292 tablet_replica.cc:333] T 00000000000000000000000000000000 P 554617fdcd4d46f48555ab345aceb015: stopping tablet replica
I20260812 06:20:27.208758 19292 master.cc:584] Master@127.18.215.62:45791 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5101 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:20:27.291622 19292 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.18.215.62:41241
I20260812 06:20:27.292055 19292 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:27.294005 19516 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:27.294118 19518 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:20:27.294181 19521 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:27.294239 19292 server_base.cc:1061] running on GCE node
I20260812 06:20:27.294386 19292 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:27.294421 19292 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:27.294441 19292 hybrid_clock.cc:648] HybridClock initialized: now 1786515627294441 us; error 0 us; skew 500 ppm
I20260812 06:20:27.295228 19292 webserver.cc:533] Webserver started at http://127.18.215.62:46803/ using document root <none> and password file <none>
I20260812 06:20:27.295380 19292 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:27.295428 19292 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:27.295511 19292 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:27.295892 19292 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515622168709-19292-0/minicluster-data/master-0-root/instance:
uuid: "120eaf043fef430ebfd6f1afc8dd4ca7"
format_stamp: "Formatted at 2026-08-12 06:20:27 on dist-test-slave-vq2q"
I20260812 06:20:27.297345 19292 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:20:27.298206 19527 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:27.298413 19292 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:27.298497 19292 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515622168709-19292-0/minicluster-data/master-0-root
uuid: "120eaf043fef430ebfd6f1afc8dd4ca7"
format_stamp: "Formatted at 2026-08-12 06:20:27 on dist-test-slave-vq2q"
I20260812 06:20:27.298563 19292 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515622168709-19292-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515622168709-19292-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515622168709-19292-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:27.304441 19292 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:27.304783 19292 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:27.309399 19292 rpc_server.cc:307] RPC server started. Bound to: 127.18.215.62:41241
I20260812 06:20:27.309742 19591 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.18.215.62:41241 every 8 connection(s)
I20260812 06:20:27.310343 19592 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:27.312071 19592 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 120eaf043fef430ebfd6f1afc8dd4ca7: Bootstrap starting.
I20260812 06:20:27.312809 19592 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 120eaf043fef430ebfd6f1afc8dd4ca7: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:27.313737 19592 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 120eaf043fef430ebfd6f1afc8dd4ca7: No bootstrap required, opened a new log
I20260812 06:20:27.314128 19592 raft_consensus.cc:359] T 00000000000000000000000000000000 P 120eaf043fef430ebfd6f1afc8dd4ca7 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "120eaf043fef430ebfd6f1afc8dd4ca7" member_type: VOTER }
I20260812 06:20:27.314215 19592 raft_consensus.cc:385] T 00000000000000000000000000000000 P 120eaf043fef430ebfd6f1afc8dd4ca7 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:27.314246 19592 raft_consensus.cc:740] T 00000000000000000000000000000000 P 120eaf043fef430ebfd6f1afc8dd4ca7 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 120eaf043fef430ebfd6f1afc8dd4ca7, State: Initialized, Role: FOLLOWER
I20260812 06:20:27.314386 19592 consensus_queue.cc:260] T 00000000000000000000000000000000 P 120eaf043fef430ebfd6f1afc8dd4ca7 [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: "120eaf043fef430ebfd6f1afc8dd4ca7" member_type: VOTER }
I20260812 06:20:27.314476 19592 raft_consensus.cc:399] T 00000000000000000000000000000000 P 120eaf043fef430ebfd6f1afc8dd4ca7 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:27.314517 19592 raft_consensus.cc:493] T 00000000000000000000000000000000 P 120eaf043fef430ebfd6f1afc8dd4ca7 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:27.314567 19592 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 120eaf043fef430ebfd6f1afc8dd4ca7 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:27.315225 19592 raft_consensus.cc:515] T 00000000000000000000000000000000 P 120eaf043fef430ebfd6f1afc8dd4ca7 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "120eaf043fef430ebfd6f1afc8dd4ca7" member_type: VOTER }
I20260812 06:20:27.315351 19592 leader_election.cc:304] T 00000000000000000000000000000000 P 120eaf043fef430ebfd6f1afc8dd4ca7 [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: 120eaf043fef430ebfd6f1afc8dd4ca7; no voters: 
I20260812 06:20:27.315515 19592 leader_election.cc:290] T 00000000000000000000000000000000 P 120eaf043fef430ebfd6f1afc8dd4ca7 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:27.315630 19597 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 120eaf043fef430ebfd6f1afc8dd4ca7 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:27.315841 19597 raft_consensus.cc:697] T 00000000000000000000000000000000 P 120eaf043fef430ebfd6f1afc8dd4ca7 [term 1 LEADER]: Becoming Leader. State: Replica: 120eaf043fef430ebfd6f1afc8dd4ca7, State: Running, Role: LEADER
I20260812 06:20:27.315929 19592 sys_catalog.cc:565] T 00000000000000000000000000000000 P 120eaf043fef430ebfd6f1afc8dd4ca7 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:27.316006 19597 consensus_queue.cc:237] T 00000000000000000000000000000000 P 120eaf043fef430ebfd6f1afc8dd4ca7 [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: "120eaf043fef430ebfd6f1afc8dd4ca7" member_type: VOTER }
I20260812 06:20:27.316426 19598 sys_catalog.cc:455] T 00000000000000000000000000000000 P 120eaf043fef430ebfd6f1afc8dd4ca7 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "120eaf043fef430ebfd6f1afc8dd4ca7" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "120eaf043fef430ebfd6f1afc8dd4ca7" member_type: VOTER } }
I20260812 06:20:27.316443 19599 sys_catalog.cc:455] T 00000000000000000000000000000000 P 120eaf043fef430ebfd6f1afc8dd4ca7 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 120eaf043fef430ebfd6f1afc8dd4ca7. Latest consensus state: current_term: 1 leader_uuid: "120eaf043fef430ebfd6f1afc8dd4ca7" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "120eaf043fef430ebfd6f1afc8dd4ca7" member_type: VOTER } }
I20260812 06:20:27.316596 19598 sys_catalog.cc:458] T 00000000000000000000000000000000 P 120eaf043fef430ebfd6f1afc8dd4ca7 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:27.316612 19599 sys_catalog.cc:458] T 00000000000000000000000000000000 P 120eaf043fef430ebfd6f1afc8dd4ca7 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:27.317124 19606 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:27.317894 19606 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:27.318105 19292 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:27.319684 19606 catalog_manager.cc:1383] Generated new cluster ID: e07f864ada5a4ad28d06efe3d89f4316
I20260812 06:20:27.319743 19606 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:27.334362 19606 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:27.334861 19606 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:27.345045 19606 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 120eaf043fef430ebfd6f1afc8dd4ca7: Generated new TSK 0
I20260812 06:20:27.345224 19606 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:27.350317 19292 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:27.352334 19619 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:20:27.352427 19618 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:27.352460 19621 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:20:27.352507 19292 server_base.cc:1061] running on GCE node
I20260812 06:20:27.352798 19292 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:27.352851 19292 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:20:27.352873 19292 hybrid_clock.cc:648] HybridClock initialized: now 1786515627352873 us; error 0 us; skew 500 ppm
I20260812 06:20:27.353767 19292 webserver.cc:533] Webserver started at http://127.18.215.1:45699/ using document root <none> and password file <none>
I20260812 06:20:27.353921 19292 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:27.353976 19292 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:27.354050 19292 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:27.354432 19292 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515622168709-19292-0/minicluster-data/ts-0-root/instance:
uuid: "dac61d7a319d49bc85d5c6f734ccc26e"
format_stamp: "Formatted at 2026-08-12 06:20:27 on dist-test-slave-vq2q"
I20260812 06:20:27.355904 19292 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:27.356817 19626 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:27.357048 19292 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:27.357115 19292 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515622168709-19292-0/minicluster-data/ts-0-root
uuid: "dac61d7a319d49bc85d5c6f734ccc26e"
format_stamp: "Formatted at 2026-08-12 06:20:27 on dist-test-slave-vq2q"
I20260812 06:20:27.357199 19292 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515622168709-19292-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515622168709-19292-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515622168709-19292-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:20:27.373919 19292 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:27.374312 19292 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:27.374625 19292 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:27.375100 19292 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:27.375137 19292 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:27.375183 19292 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:27.375211 19292 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:27.379259 19292 rpc_server.cc:307] RPC server started. Bound to: 127.18.215.1:40369
I20260812 06:20:27.380641 19705 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.18.215.1:40369 every 8 connection(s)
I20260812 06:20:27.387995 19706 heartbeater.cc:344] Connected to a master server at 127.18.215.62:41241
I20260812 06:20:27.388103 19706 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:27.388338 19706 heartbeater.cc:507] Master 127.18.215.62:41241 requested a full tablet report, sending...
I20260812 06:20:27.389041 19539 ts_manager.cc:194] Registered new tserver with Master: dac61d7a319d49bc85d5c6f734ccc26e (127.18.215.1:40369)
I20260812 06:20:27.389770 19539 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:32800
I20260812 06:20:27.389950 19292 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.009947202s
I20260812 06:20:27.396498 19539 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:32814:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:20:27.405035 19662 tablet_service.cc:1511] Processing CreateTablet for tablet e71bab6a82f147ad96b3eadb2a8f34f4 (DEFAULT_TABLE table=heavy-update-compaction-test [id=8d14d7b7606b4cc8aa306401601d648b]), partition=
I20260812 06:20:27.405318 19662 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet e71bab6a82f147ad96b3eadb2a8f34f4. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:27.407253 19718 tablet_bootstrap.cc:492] T e71bab6a82f147ad96b3eadb2a8f34f4 P dac61d7a319d49bc85d5c6f734ccc26e: Bootstrap starting.
I20260812 06:20:27.408123 19718 tablet_bootstrap.cc:654] T e71bab6a82f147ad96b3eadb2a8f34f4 P dac61d7a319d49bc85d5c6f734ccc26e: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:27.409049 19718 tablet_bootstrap.cc:492] T e71bab6a82f147ad96b3eadb2a8f34f4 P dac61d7a319d49bc85d5c6f734ccc26e: No bootstrap required, opened a new log
I20260812 06:20:27.409132 19718 ts_tablet_manager.cc:1403] T e71bab6a82f147ad96b3eadb2a8f34f4 P dac61d7a319d49bc85d5c6f734ccc26e: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:20:27.409549 19718 raft_consensus.cc:359] T e71bab6a82f147ad96b3eadb2a8f34f4 P dac61d7a319d49bc85d5c6f734ccc26e [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "dac61d7a319d49bc85d5c6f734ccc26e" member_type: VOTER last_known_addr { host: "127.18.215.1" port: 40369 } }
I20260812 06:20:27.409638 19718 raft_consensus.cc:385] T e71bab6a82f147ad96b3eadb2a8f34f4 P dac61d7a319d49bc85d5c6f734ccc26e [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:27.409668 19718 raft_consensus.cc:740] T e71bab6a82f147ad96b3eadb2a8f34f4 P dac61d7a319d49bc85d5c6f734ccc26e [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: dac61d7a319d49bc85d5c6f734ccc26e, State: Initialized, Role: FOLLOWER
I20260812 06:20:27.409788 19718 consensus_queue.cc:260] T e71bab6a82f147ad96b3eadb2a8f34f4 P dac61d7a319d49bc85d5c6f734ccc26e [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: "dac61d7a319d49bc85d5c6f734ccc26e" member_type: VOTER last_known_addr { host: "127.18.215.1" port: 40369 } }
I20260812 06:20:27.409868 19718 raft_consensus.cc:399] T e71bab6a82f147ad96b3eadb2a8f34f4 P dac61d7a319d49bc85d5c6f734ccc26e [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:27.409907 19718 raft_consensus.cc:493] T e71bab6a82f147ad96b3eadb2a8f34f4 P dac61d7a319d49bc85d5c6f734ccc26e [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:27.409955 19718 raft_consensus.cc:3060] T e71bab6a82f147ad96b3eadb2a8f34f4 P dac61d7a319d49bc85d5c6f734ccc26e [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:27.410718 19718 raft_consensus.cc:515] T e71bab6a82f147ad96b3eadb2a8f34f4 P dac61d7a319d49bc85d5c6f734ccc26e [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "dac61d7a319d49bc85d5c6f734ccc26e" member_type: VOTER last_known_addr { host: "127.18.215.1" port: 40369 } }
I20260812 06:20:27.410852 19718 leader_election.cc:304] T e71bab6a82f147ad96b3eadb2a8f34f4 P dac61d7a319d49bc85d5c6f734ccc26e [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: dac61d7a319d49bc85d5c6f734ccc26e; no voters: 
I20260812 06:20:27.411019 19718 leader_election.cc:290] T e71bab6a82f147ad96b3eadb2a8f34f4 P dac61d7a319d49bc85d5c6f734ccc26e [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:27.411113 19720 raft_consensus.cc:2804] T e71bab6a82f147ad96b3eadb2a8f34f4 P dac61d7a319d49bc85d5c6f734ccc26e [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:27.411294 19718 ts_tablet_manager.cc:1434] T e71bab6a82f147ad96b3eadb2a8f34f4 P dac61d7a319d49bc85d5c6f734ccc26e: Time spent starting tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:20:27.411329 19720 raft_consensus.cc:697] T e71bab6a82f147ad96b3eadb2a8f34f4 P dac61d7a319d49bc85d5c6f734ccc26e [term 1 LEADER]: Becoming Leader. State: Replica: dac61d7a319d49bc85d5c6f734ccc26e, State: Running, Role: LEADER
I20260812 06:20:27.411362 19706 heartbeater.cc:499] Master 127.18.215.62:41241 was elected leader, sending a full tablet report...
I20260812 06:20:27.411510 19720 consensus_queue.cc:237] T e71bab6a82f147ad96b3eadb2a8f34f4 P dac61d7a319d49bc85d5c6f734ccc26e [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: "dac61d7a319d49bc85d5c6f734ccc26e" member_type: VOTER last_known_addr { host: "127.18.215.1" port: 40369 } }
I20260812 06:20:27.412762 19539 catalog_manager.cc:5719] T e71bab6a82f147ad96b3eadb2a8f34f4 P dac61d7a319d49bc85d5c6f734ccc26e reported cstate change: term changed from 0 to 1, leader changed from <none> to dac61d7a319d49bc85d5c6f734ccc26e (127.18.215.1). New cstate: current_term: 1 leader_uuid: "dac61d7a319d49bc85d5c6f734ccc26e" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "dac61d7a319d49bc85d5c6f734ccc26e" member_type: VOTER last_known_addr { host: "127.18.215.1" port: 40369 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:27.466536 19292 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.051s	user 0.012s	sys 0.010s
I20260812 06:20:27.631167 19707 maintenance_manager.cc:419] P dac61d7a319d49bc85d5c6f734ccc26e: Scheduling FlushMRSOp(e71bab6a82f147ad96b3eadb2a8f34f4): perf score=19.054940
I20260812 06:20:27.782390 19633 maintenance_manager.cc:643] P dac61d7a319d49bc85d5c6f734ccc26e: FlushMRSOp(e71bab6a82f147ad96b3eadb2a8f34f4) complete. Timing: real 0.151s	user 0.109s	sys 0.040s Metrics: {"bytes_written":12307492,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":72,"dirs.run_cpu_time_us":178,"dirs.run_wall_time_us":815,"drs_written":1,"lbm_read_time_us":40,"lbm_reads_lt_1ms":4,"lbm_write_time_us":38373,"lbm_writes_lt_1ms":767,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"spinlock_wait_cycles":2432,"update_count":1500}
I20260812 06:20:27.783331 19707 maintenance_manager.cc:419] P dac61d7a319d49bc85d5c6f734ccc26e: Scheduling LogGCOp(e71bab6a82f147ad96b3eadb2a8f34f4): free 20743831 bytes of WAL
I20260812 06:20:27.783672 19633 log_reader.cc:385] T e71bab6a82f147ad96b3eadb2a8f34f4: removed 2 log segments from log reader
I20260812 06:20:27.783762 19633 log.cc:1079] T e71bab6a82f147ad96b3eadb2a8f34f4 P dac61d7a319d49bc85d5c6f734ccc26e: Deleting log segment in path: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515622168709-19292-0/minicluster-data/ts-0-root/wals/e71bab6a82f147ad96b3eadb2a8f34f4/wal-000000001 (ops 1-6)
I20260812 06:20:27.783838 19633 log.cc:1079] T e71bab6a82f147ad96b3eadb2a8f34f4 P dac61d7a319d49bc85d5c6f734ccc26e: Deleting log segment in path: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515622168709-19292-0/minicluster-data/ts-0-root/wals/e71bab6a82f147ad96b3eadb2a8f34f4/wal-000000002 (ops 7-11)
I20260812 06:20:27.787820 19633 maintenance_manager.cc:643] P dac61d7a319d49bc85d5c6f734ccc26e: LogGCOp(e71bab6a82f147ad96b3eadb2a8f34f4) complete. Timing: real 0.004s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:20:27.788159 19707 maintenance_manager.cc:419] P dac61d7a319d49bc85d5c6f734ccc26e: Scheduling UndoDeltaBlockGCOp(e71bab6a82f147ad96b3eadb2a8f34f4): 16821654 bytes on disk
I20260812 06:20:27.788532 19633 maintenance_manager.cc:643] P dac61d7a319d49bc85d5c6f734ccc26e: UndoDeltaBlockGCOp(e71bab6a82f147ad96b3eadb2a8f34f4) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":47,"lbm_reads_lt_1ms":4}
I20260812 06:20:27.788915 19707 maintenance_manager.cc:419] P dac61d7a319d49bc85d5c6f734ccc26e: Scheduling FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4): perf score=2.188937
I20260812 06:20:27.817898 19633 maintenance_manager.cc:643] P dac61d7a319d49bc85d5c6f734ccc26e: FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4) complete. Timing: real 0.029s	user 0.010s	sys 0.000s Metrics: {"bytes_written":3897534,"delete_count":0,"lbm_write_time_us":3627,"lbm_writes_lt_1ms":98,"reinsert_count":0,"update_count":475}
I20260812 06:20:27.818756 19707 maintenance_manager.cc:419] P dac61d7a319d49bc85d5c6f734ccc26e: Scheduling FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4): perf score=2.188937
I20260812 06:20:27.834237 19633 maintenance_manager.cc:643] P dac61d7a319d49bc85d5c6f734ccc26e: FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4) complete. Timing: real 0.015s	user 0.009s	sys 0.005s Metrics: {"bytes_written":3897534,"delete_count":0,"lbm_write_time_us":5648,"lbm_writes_lt_1ms":98,"reinsert_count":0,"update_count":475}
I20260812 06:20:27.834923 19707 maintenance_manager.cc:419] P dac61d7a319d49bc85d5c6f734ccc26e: Scheduling MajorDeltaCompactionOp(e71bab6a82f147ad96b3eadb2a8f34f4): perf score=1.000000
I20260812 06:20:28.022714 19633 maintenance_manager.cc:643] P dac61d7a319d49bc85d5c6f734ccc26e: MajorDeltaCompactionOp(e71bab6a82f147ad96b3eadb2a8f34f4) complete. Timing: real 0.188s	user 0.099s	sys 0.077s Metrics: {"cfile_cache_miss":523,"cfile_cache_miss_bytes":24405555,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":485,"lbm_read_time_us":11773,"lbm_reads_lt_1ms":559,"lbm_write_time_us":26833,"lbm_writes_lt_1ms":533,"peak_mem_usage":61665166,"reinsert_count":0,"spinlock_wait_cycles":1280,"thread_start_us":307,"threads_started":5,"update_count":2450}
I20260812 06:20:28.023296 19707 maintenance_manager.cc:419] P dac61d7a319d49bc85d5c6f734ccc26e: Scheduling FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4): perf score=14.095187
I20260812 06:20:28.072228 19633 maintenance_manager.cc:643] P dac61d7a319d49bc85d5c6f734ccc26e: FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4) complete. Timing: real 0.049s	user 0.019s	sys 0.023s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19600,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:28.072739 19707 maintenance_manager.cc:419] P dac61d7a319d49bc85d5c6f734ccc26e: Scheduling FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4): perf score=2.188937
I20260812 06:20:28.083592 19633 maintenance_manager.cc:643] P dac61d7a319d49bc85d5c6f734ccc26e: FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4) complete. Timing: real 0.011s	user 0.006s	sys 0.002s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3791,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:28.084061 19707 maintenance_manager.cc:419] P dac61d7a319d49bc85d5c6f734ccc26e: Scheduling MajorDeltaCompactionOp(e71bab6a82f147ad96b3eadb2a8f34f4): perf score=1.000000
I20260812 06:20:28.251272 19633 maintenance_manager.cc:643] P dac61d7a319d49bc85d5c6f734ccc26e: MajorDeltaCompactionOp(e71bab6a82f147ad96b3eadb2a8f34f4) complete. Timing: real 0.167s	user 0.105s	sys 0.058s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":162,"lbm_read_time_us":9974,"lbm_reads_lt_1ms":572,"lbm_write_time_us":24309,"lbm_writes_lt_1ms":543,"mutex_wait_us":38,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":16512,"update_count":2500}
I20260812 06:20:28.251806 19707 maintenance_manager.cc:419] P dac61d7a319d49bc85d5c6f734ccc26e: Scheduling FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4): perf score=14.095187
I20260812 06:20:28.292461 19633 maintenance_manager.cc:643] P dac61d7a319d49bc85d5c6f734ccc26e: FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4) complete. Timing: real 0.040s	user 0.015s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":16074,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2000}
I20260812 06:20:28.293102 19707 maintenance_manager.cc:419] P dac61d7a319d49bc85d5c6f734ccc26e: Scheduling FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4): perf score=2.188937
I20260812 06:20:28.309479 19633 maintenance_manager.cc:643] P dac61d7a319d49bc85d5c6f734ccc26e: FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4) complete. Timing: real 0.016s	user 0.007s	sys 0.009s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6159,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:28.310091 19707 maintenance_manager.cc:419] P dac61d7a319d49bc85d5c6f734ccc26e: Scheduling MajorDeltaCompactionOp(e71bab6a82f147ad96b3eadb2a8f34f4): perf score=1.000000
I20260812 06:20:28.466744 19633 maintenance_manager.cc:643] P dac61d7a319d49bc85d5c6f734ccc26e: MajorDeltaCompactionOp(e71bab6a82f147ad96b3eadb2a8f34f4) complete. Timing: real 0.156s	user 0.117s	sys 0.033s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":704,"lbm_read_time_us":11083,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27298,"lbm_writes_lt_1ms":543,"mutex_wait_us":47,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":22272,"update_count":2500}
I20260812 06:20:28.467361 19707 maintenance_manager.cc:419] P dac61d7a319d49bc85d5c6f734ccc26e: Scheduling FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4): perf score=11.118625
I20260812 06:20:28.513789 19633 maintenance_manager.cc:643] P dac61d7a319d49bc85d5c6f734ccc26e: FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4) complete. Timing: real 0.046s	user 0.015s	sys 0.028s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":18419,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:20:28.514334 19707 maintenance_manager.cc:419] P dac61d7a319d49bc85d5c6f734ccc26e: Scheduling FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4): perf score=2.188937
I20260812 06:20:28.525800 19633 maintenance_manager.cc:643] P dac61d7a319d49bc85d5c6f734ccc26e: FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3559,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:28.526257 19707 maintenance_manager.cc:419] P dac61d7a319d49bc85d5c6f734ccc26e: Scheduling FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4): perf score=2.188937
I20260812 06:20:28.535122 19633 maintenance_manager.cc:643] P dac61d7a319d49bc85d5c6f734ccc26e: FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4) complete. Timing: real 0.009s	user 0.007s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3080,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:28.535549 19707 maintenance_manager.cc:419] P dac61d7a319d49bc85d5c6f734ccc26e: Scheduling MajorDeltaCompactionOp(e71bab6a82f147ad96b3eadb2a8f34f4): perf score=1.000000
I20260812 06:20:28.683065 19633 maintenance_manager.cc:643] P dac61d7a319d49bc85d5c6f734ccc26e: MajorDeltaCompactionOp(e71bab6a82f147ad96b3eadb2a8f34f4) complete. Timing: real 0.147s	user 0.127s	sys 0.020s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815794,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":522,"lbm_read_time_us":11890,"lbm_reads_lt_1ms":573,"lbm_write_time_us":28462,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11520,"update_count":2500}
I20260812 06:20:28.683670 19707 maintenance_manager.cc:419] P dac61d7a319d49bc85d5c6f734ccc26e: Scheduling FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4): perf score=11.118625
I20260812 06:20:28.725365 19633 maintenance_manager.cc:643] P dac61d7a319d49bc85d5c6f734ccc26e: FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4) complete. Timing: real 0.041s	user 0.038s	sys 0.003s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":16017,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:28.725852 19707 maintenance_manager.cc:419] P dac61d7a319d49bc85d5c6f734ccc26e: Scheduling FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4): perf score=2.188937
I20260812 06:20:28.748689 19633 maintenance_manager.cc:643] P dac61d7a319d49bc85d5c6f734ccc26e: FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4) complete. Timing: real 0.023s	user 0.010s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4684,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:28.749136 19707 maintenance_manager.cc:419] P dac61d7a319d49bc85d5c6f734ccc26e: Scheduling FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4): perf score=2.188937
I20260812 06:20:28.759021 19633 maintenance_manager.cc:643] P dac61d7a319d49bc85d5c6f734ccc26e: FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3467,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:28.759430 19707 maintenance_manager.cc:419] P dac61d7a319d49bc85d5c6f734ccc26e: Scheduling MajorDeltaCompactionOp(e71bab6a82f147ad96b3eadb2a8f34f4): perf score=1.000000
I20260812 06:20:28.901249 19633 maintenance_manager.cc:643] P dac61d7a319d49bc85d5c6f734ccc26e: MajorDeltaCompactionOp(e71bab6a82f147ad96b3eadb2a8f34f4) complete. Timing: real 0.142s	user 0.121s	sys 0.019s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815794,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1141,"lbm_read_time_us":9450,"lbm_reads_lt_1ms":573,"lbm_write_time_us":27396,"lbm_writes_lt_1ms":543,"mutex_wait_us":774,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7424,"update_count":2500}
I20260812 06:20:28.902134 19707 maintenance_manager.cc:419] P dac61d7a319d49bc85d5c6f734ccc26e: Scheduling FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4): perf score=10.126437
I20260812 06:20:28.941619 19633 maintenance_manager.cc:643] P dac61d7a319d49bc85d5c6f734ccc26e: FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4) complete. Timing: real 0.039s	user 0.031s	sys 0.007s Metrics: {"bytes_written":12594659,"delete_count":0,"lbm_write_time_us":16255,"lbm_writes_lt_1ms":310,"reinsert_count":0,"update_count":1535}
I20260812 06:20:28.942159 19707 maintenance_manager.cc:419] P dac61d7a319d49bc85d5c6f734ccc26e: Scheduling FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4): perf score=2.188937
I20260812 06:20:28.951784 19633 maintenance_manager.cc:643] P dac61d7a319d49bc85d5c6f734ccc26e: FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3815484,"delete_count":0,"lbm_write_time_us":3518,"lbm_writes_lt_1ms":96,"reinsert_count":0,"update_count":465}
I20260812 06:20:28.952215 19707 maintenance_manager.cc:419] P dac61d7a319d49bc85d5c6f734ccc26e: Scheduling FlushMRSOp(e71bab6a82f147ad96b3eadb2a8f34f4): perf score=1.000000
I20260812 06:20:28.979490 19633 maintenance_manager.cc:643] P dac61d7a319d49bc85d5c6f734ccc26e: FlushMRSOp(e71bab6a82f147ad96b3eadb2a8f34f4) complete. Timing: real 0.027s	user 0.025s	sys 0.000s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":62,"dirs.run_cpu_time_us":225,"dirs.run_wall_time_us":1237,"drs_written":1,"lbm_read_time_us":51,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1363,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:20:28.980155 19707 maintenance_manager.cc:419] P dac61d7a319d49bc85d5c6f734ccc26e: Scheduling LogGCOp(e71bab6a82f147ad96b3eadb2a8f34f4): free 112239364 bytes of WAL
I20260812 06:20:28.980388 19633 log_reader.cc:385] T e71bab6a82f147ad96b3eadb2a8f34f4: removed 11 log segments from log reader
I20260812 06:20:28.980446 19633 log.cc:1079] T e71bab6a82f147ad96b3eadb2a8f34f4 P dac61d7a319d49bc85d5c6f734ccc26e: Deleting log segment in path: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515622168709-19292-0/minicluster-data/ts-0-root/wals/e71bab6a82f147ad96b3eadb2a8f34f4/wal-000000003 (ops 12-16)
I20260812 06:20:28.980492 19633 log.cc:1079] T e71bab6a82f147ad96b3eadb2a8f34f4 P dac61d7a319d49bc85d5c6f734ccc26e: Deleting log segment in path: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515622168709-19292-0/minicluster-data/ts-0-root/wals/e71bab6a82f147ad96b3eadb2a8f34f4/wal-000000004 (ops 17-21)
I20260812 06:20:28.980536 19633 log.cc:1079] T e71bab6a82f147ad96b3eadb2a8f34f4 P dac61d7a319d49bc85d5c6f734ccc26e: Deleting log segment in path: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515622168709-19292-0/minicluster-data/ts-0-root/wals/e71bab6a82f147ad96b3eadb2a8f34f4/wal-000000005 (ops 22-26)
I20260812 06:20:28.980566 19633 log.cc:1079] T e71bab6a82f147ad96b3eadb2a8f34f4 P dac61d7a319d49bc85d5c6f734ccc26e: Deleting log segment in path: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515622168709-19292-0/minicluster-data/ts-0-root/wals/e71bab6a82f147ad96b3eadb2a8f34f4/wal-000000006 (ops 27-31)
I20260812 06:20:28.980594 19633 log.cc:1079] T e71bab6a82f147ad96b3eadb2a8f34f4 P dac61d7a319d49bc85d5c6f734ccc26e: Deleting log segment in path: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515622168709-19292-0/minicluster-data/ts-0-root/wals/e71bab6a82f147ad96b3eadb2a8f34f4/wal-000000007 (ops 32-36)
I20260812 06:20:28.980621 19633 log.cc:1079] T e71bab6a82f147ad96b3eadb2a8f34f4 P dac61d7a319d49bc85d5c6f734ccc26e: Deleting log segment in path: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515622168709-19292-0/minicluster-data/ts-0-root/wals/e71bab6a82f147ad96b3eadb2a8f34f4/wal-000000008 (ops 37-40)
I20260812 06:20:28.980652 19633 log.cc:1079] T e71bab6a82f147ad96b3eadb2a8f34f4 P dac61d7a319d49bc85d5c6f734ccc26e: Deleting log segment in path: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515622168709-19292-0/minicluster-data/ts-0-root/wals/e71bab6a82f147ad96b3eadb2a8f34f4/wal-000000009 (ops 41-45)
I20260812 06:20:28.980683 19633 log.cc:1079] T e71bab6a82f147ad96b3eadb2a8f34f4 P dac61d7a319d49bc85d5c6f734ccc26e: Deleting log segment in path: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515622168709-19292-0/minicluster-data/ts-0-root/wals/e71bab6a82f147ad96b3eadb2a8f34f4/wal-000000010 (ops 46-50)
I20260812 06:20:28.980712 19633 log.cc:1079] T e71bab6a82f147ad96b3eadb2a8f34f4 P dac61d7a319d49bc85d5c6f734ccc26e: Deleting log segment in path: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515622168709-19292-0/minicluster-data/ts-0-root/wals/e71bab6a82f147ad96b3eadb2a8f34f4/wal-000000011 (ops 51-55)
I20260812 06:20:28.980741 19633 log.cc:1079] T e71bab6a82f147ad96b3eadb2a8f34f4 P dac61d7a319d49bc85d5c6f734ccc26e: Deleting log segment in path: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515622168709-19292-0/minicluster-data/ts-0-root/wals/e71bab6a82f147ad96b3eadb2a8f34f4/wal-000000012 (ops 56-60)
I20260812 06:20:28.980767 19633 log.cc:1079] T e71bab6a82f147ad96b3eadb2a8f34f4 P dac61d7a319d49bc85d5c6f734ccc26e: Deleting log segment in path: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515622168709-19292-0/minicluster-data/ts-0-root/wals/e71bab6a82f147ad96b3eadb2a8f34f4/wal-000000013 (ops 61-65)
I20260812 06:20:29.004325 19633 maintenance_manager.cc:643] P dac61d7a319d49bc85d5c6f734ccc26e: LogGCOp(e71bab6a82f147ad96b3eadb2a8f34f4) complete. Timing: real 0.024s	user 0.000s	sys 0.021s Metrics: {}
I20260812 06:20:29.004792 19707 maintenance_manager.cc:419] P dac61d7a319d49bc85d5c6f734ccc26e: Scheduling FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4): perf score=3.181125
I20260812 06:20:29.021147 19633 maintenance_manager.cc:643] P dac61d7a319d49bc85d5c6f734ccc26e: FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4) complete. Timing: real 0.016s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4145,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:29.021641 19707 maintenance_manager.cc:419] P dac61d7a319d49bc85d5c6f734ccc26e: Scheduling UndoDeltaBlockGCOp(e71bab6a82f147ad96b3eadb2a8f34f4): 448 bytes on disk
I20260812 06:20:29.022079 19633 maintenance_manager.cc:643] P dac61d7a319d49bc85d5c6f734ccc26e: UndoDeltaBlockGCOp(e71bab6a82f147ad96b3eadb2a8f34f4) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4}
I20260812 06:20:29.022568 19707 maintenance_manager.cc:419] P dac61d7a319d49bc85d5c6f734ccc26e: Scheduling FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4): perf score=2.188937
I20260812 06:20:29.036924 19633 maintenance_manager.cc:643] P dac61d7a319d49bc85d5c6f734ccc26e: FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4) complete. Timing: real 0.014s	user 0.007s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5175,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:29.037582 19707 maintenance_manager.cc:419] P dac61d7a319d49bc85d5c6f734ccc26e: Scheduling MajorDeltaCompactionOp(e71bab6a82f147ad96b3eadb2a8f34f4): perf score=1.000000
I20260812 06:20:29.202988 19633 maintenance_manager.cc:643] P dac61d7a319d49bc85d5c6f734ccc26e: MajorDeltaCompactionOp(e71bab6a82f147ad96b3eadb2a8f34f4) complete. Timing: real 0.165s	user 0.117s	sys 0.048s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28918315,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":805,"lbm_read_time_us":13130,"lbm_reads_lt_1ms":674,"lbm_write_time_us":31223,"lbm_writes_lt_1ms":643,"mutex_wait_us":56,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":6528,"thread_start_us":79,"threads_started":1,"update_count":3000}
I20260812 06:20:29.203555 19707 maintenance_manager.cc:419] P dac61d7a319d49bc85d5c6f734ccc26e: Scheduling FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4): perf score=14.095187
I20260812 06:20:29.245253 19633 maintenance_manager.cc:643] P dac61d7a319d49bc85d5c6f734ccc26e: FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4) complete. Timing: real 0.041s	user 0.026s	sys 0.016s Metrics: {"bytes_written":16409906,"delete_count":0,"lbm_write_time_us":18045,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:29.245685 19707 maintenance_manager.cc:419] P dac61d7a319d49bc85d5c6f734ccc26e: Scheduling FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4): perf score=2.188937
I20260812 06:20:29.256373 19633 maintenance_manager.cc:643] P dac61d7a319d49bc85d5c6f734ccc26e: FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4) complete. Timing: real 0.011s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3578,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:29.256901 19707 maintenance_manager.cc:419] P dac61d7a319d49bc85d5c6f734ccc26e: Scheduling MajorDeltaCompactionOp(e71bab6a82f147ad96b3eadb2a8f34f4): perf score=1.000000
I20260812 06:20:29.403584 19633 maintenance_manager.cc:643] P dac61d7a319d49bc85d5c6f734ccc26e: MajorDeltaCompactionOp(e71bab6a82f147ad96b3eadb2a8f34f4) complete. Timing: real 0.146s	user 0.106s	sys 0.039s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":301,"lbm_read_time_us":11130,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27249,"lbm_writes_lt_1ms":543,"mutex_wait_us":54,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":40192,"update_count":2500}
I20260812 06:20:29.404238 19707 maintenance_manager.cc:419] P dac61d7a319d49bc85d5c6f734ccc26e: Scheduling FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4): perf score=12.110812
I20260812 06:20:29.444164 19633 maintenance_manager.cc:643] P dac61d7a319d49bc85d5c6f734ccc26e: FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4) complete. Timing: real 0.040s	user 0.028s	sys 0.009s Metrics: {"bytes_written":13866410,"delete_count":0,"lbm_write_time_us":17164,"lbm_writes_lt_1ms":341,"reinsert_count":0,"update_count":1690}
I20260812 06:20:29.444723 19707 maintenance_manager.cc:419] P dac61d7a319d49bc85d5c6f734ccc26e: Scheduling FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4): perf score=1.196750
I20260812 06:20:29.455394 19633 maintenance_manager.cc:643] P dac61d7a319d49bc85d5c6f734ccc26e: FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":2543704,"delete_count":0,"lbm_write_time_us":3792,"lbm_writes_lt_1ms":65,"reinsert_count":0,"update_count":310}
I20260812 06:20:29.455899 19707 maintenance_manager.cc:419] P dac61d7a319d49bc85d5c6f734ccc26e: Scheduling MajorDeltaCompactionOp(e71bab6a82f147ad96b3eadb2a8f34f4): perf score=1.000000
I20260812 06:20:29.598635 19633 maintenance_manager.cc:643] P dac61d7a319d49bc85d5c6f734ccc26e: MajorDeltaCompactionOp(e71bab6a82f147ad96b3eadb2a8f34f4) complete. Timing: real 0.143s	user 0.094s	sys 0.047s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713237,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":872,"lbm_read_time_us":11346,"lbm_reads_lt_1ms":468,"lbm_write_time_us":22231,"lbm_writes_lt_1ms":443,"mutex_wait_us":232,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3200,"update_count":2000}
I20260812 06:20:29.599159 19707 maintenance_manager.cc:419] P dac61d7a319d49bc85d5c6f734ccc26e: Scheduling FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4): perf score=11.118625
I20260812 06:20:29.636327 19633 maintenance_manager.cc:643] P dac61d7a319d49bc85d5c6f734ccc26e: FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4) complete. Timing: real 0.037s	user 0.021s	sys 0.011s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":14935,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:29.636849 19707 maintenance_manager.cc:419] P dac61d7a319d49bc85d5c6f734ccc26e: Scheduling FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4): perf score=2.188937
I20260812 06:20:29.651698 19633 maintenance_manager.cc:643] P dac61d7a319d49bc85d5c6f734ccc26e: FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4) complete. Timing: real 0.015s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3946,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:29.652154 19707 maintenance_manager.cc:419] P dac61d7a319d49bc85d5c6f734ccc26e: Scheduling FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4): perf score=2.188937
I20260812 06:20:29.669039 19633 maintenance_manager.cc:643] P dac61d7a319d49bc85d5c6f734ccc26e: FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4) complete. Timing: real 0.017s	user 0.006s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3469,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:29.669551 19707 maintenance_manager.cc:419] P dac61d7a319d49bc85d5c6f734ccc26e: Scheduling MajorDeltaCompactionOp(e71bab6a82f147ad96b3eadb2a8f34f4): perf score=1.000000
I20260812 06:20:29.842370 19633 maintenance_manager.cc:643] P dac61d7a319d49bc85d5c6f734ccc26e: MajorDeltaCompactionOp(e71bab6a82f147ad96b3eadb2a8f34f4) complete. Timing: real 0.173s	user 0.105s	sys 0.065s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815795,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":750,"lbm_read_time_us":12319,"lbm_reads_lt_1ms":573,"lbm_write_time_us":26979,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:20:29.842962 19707 maintenance_manager.cc:419] P dac61d7a319d49bc85d5c6f734ccc26e: Scheduling FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4): perf score=11.118625
I20260812 06:20:29.872721 19633 maintenance_manager.cc:643] P dac61d7a319d49bc85d5c6f734ccc26e: FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4) complete. Timing: real 0.030s	user 0.018s	sys 0.008s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":11786,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:29.873358 19707 maintenance_manager.cc:419] P dac61d7a319d49bc85d5c6f734ccc26e: Scheduling FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4): perf score=2.188937
I20260812 06:20:29.897923 19633 maintenance_manager.cc:643] P dac61d7a319d49bc85d5c6f734ccc26e: FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4) complete. Timing: real 0.024s	user 0.007s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4593,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:29.898427 19707 maintenance_manager.cc:419] P dac61d7a319d49bc85d5c6f734ccc26e: Scheduling FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4): perf score=2.188937
I20260812 06:20:29.908737 19633 maintenance_manager.cc:643] P dac61d7a319d49bc85d5c6f734ccc26e: FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4017,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:29.909215 19707 maintenance_manager.cc:419] P dac61d7a319d49bc85d5c6f734ccc26e: Scheduling MajorDeltaCompactionOp(e71bab6a82f147ad96b3eadb2a8f34f4): perf score=1.000000
I20260812 06:20:30.081794 19633 maintenance_manager.cc:643] P dac61d7a319d49bc85d5c6f734ccc26e: MajorDeltaCompactionOp(e71bab6a82f147ad96b3eadb2a8f34f4) complete. Timing: real 0.172s	user 0.087s	sys 0.079s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815795,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1400,"lbm_read_time_us":11940,"lbm_reads_lt_1ms":573,"lbm_write_time_us":27001,"lbm_writes_lt_1ms":543,"mutex_wait_us":437,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":40576,"update_count":2500}
I20260812 06:20:30.082311 19707 maintenance_manager.cc:419] P dac61d7a319d49bc85d5c6f734ccc26e: Scheduling FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4): perf score=14.095187
I20260812 06:20:30.123108 19633 maintenance_manager.cc:643] P dac61d7a319d49bc85d5c6f734ccc26e: FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4) complete. Timing: real 0.041s	user 0.023s	sys 0.013s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":17438,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:30.123672 19707 maintenance_manager.cc:419] P dac61d7a319d49bc85d5c6f734ccc26e: Scheduling FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4): perf score=2.188937
I20260812 06:20:30.134681 19633 maintenance_manager.cc:643] P dac61d7a319d49bc85d5c6f734ccc26e: FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3904,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:30.135106 19707 maintenance_manager.cc:419] P dac61d7a319d49bc85d5c6f734ccc26e: Scheduling MajorDeltaCompactionOp(e71bab6a82f147ad96b3eadb2a8f34f4): perf score=1.000000
I20260812 06:20:30.282281 19633 maintenance_manager.cc:643] P dac61d7a319d49bc85d5c6f734ccc26e: MajorDeltaCompactionOp(e71bab6a82f147ad96b3eadb2a8f34f4) complete. Timing: real 0.147s	user 0.106s	sys 0.038s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":770,"lbm_read_time_us":9494,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28346,"lbm_writes_lt_1ms":543,"mutex_wait_us":52,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12672,"update_count":2500}
I20260812 06:20:30.282943 19707 maintenance_manager.cc:419] P dac61d7a319d49bc85d5c6f734ccc26e: Scheduling FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4): perf score=11.118625
I20260812 06:20:30.312572 19633 maintenance_manager.cc:643] P dac61d7a319d49bc85d5c6f734ccc26e: FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4) complete. Timing: real 0.029s	user 0.018s	sys 0.008s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":11975,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:30.313109 19707 maintenance_manager.cc:419] P dac61d7a319d49bc85d5c6f734ccc26e: Scheduling FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4): perf score=2.188937
I20260812 06:20:30.337946 19633 maintenance_manager.cc:643] P dac61d7a319d49bc85d5c6f734ccc26e: FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4) complete. Timing: real 0.025s	user 0.007s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4771,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:30.338539 19707 maintenance_manager.cc:419] P dac61d7a319d49bc85d5c6f734ccc26e: Scheduling FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4): perf score=2.188937
I20260812 06:20:30.353876 19633 maintenance_manager.cc:643] P dac61d7a319d49bc85d5c6f734ccc26e: FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4) complete. Timing: real 0.015s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5576,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:30.354416 19707 maintenance_manager.cc:419] P dac61d7a319d49bc85d5c6f734ccc26e: Scheduling FlushMRSOp(e71bab6a82f147ad96b3eadb2a8f34f4): perf score=1.000000
I20260812 06:20:30.382872 19633 maintenance_manager.cc:643] P dac61d7a319d49bc85d5c6f734ccc26e: FlushMRSOp(e71bab6a82f147ad96b3eadb2a8f34f4) complete. Timing: real 0.028s	user 0.026s	sys 0.001s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":45,"dirs.run_cpu_time_us":170,"dirs.run_wall_time_us":1261,"drs_written":1,"lbm_read_time_us":57,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1479,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:20:30.383560 19707 maintenance_manager.cc:419] P dac61d7a319d49bc85d5c6f734ccc26e: Scheduling LogGCOp(e71bab6a82f147ad96b3eadb2a8f34f4): free 132571328 bytes of WAL
I20260812 06:20:30.383814 19633 log_reader.cc:385] T e71bab6a82f147ad96b3eadb2a8f34f4: removed 13 log segments from log reader
I20260812 06:20:30.383873 19633 log.cc:1079] T e71bab6a82f147ad96b3eadb2a8f34f4 P dac61d7a319d49bc85d5c6f734ccc26e: Deleting log segment in path: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515622168709-19292-0/minicluster-data/ts-0-root/wals/e71bab6a82f147ad96b3eadb2a8f34f4/wal-000000014 (ops 66-70)
I20260812 06:20:30.383913 19633 log.cc:1079] T e71bab6a82f147ad96b3eadb2a8f34f4 P dac61d7a319d49bc85d5c6f734ccc26e: Deleting log segment in path: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515622168709-19292-0/minicluster-data/ts-0-root/wals/e71bab6a82f147ad96b3eadb2a8f34f4/wal-000000015 (ops 71-75)
I20260812 06:20:30.383950 19633 log.cc:1079] T e71bab6a82f147ad96b3eadb2a8f34f4 P dac61d7a319d49bc85d5c6f734ccc26e: Deleting log segment in path: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515622168709-19292-0/minicluster-data/ts-0-root/wals/e71bab6a82f147ad96b3eadb2a8f34f4/wal-000000016 (ops 76-80)
I20260812 06:20:30.383986 19633 log.cc:1079] T e71bab6a82f147ad96b3eadb2a8f34f4 P dac61d7a319d49bc85d5c6f734ccc26e: Deleting log segment in path: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515622168709-19292-0/minicluster-data/ts-0-root/wals/e71bab6a82f147ad96b3eadb2a8f34f4/wal-000000017 (ops 81-85)
I20260812 06:20:30.384016 19633 log.cc:1079] T e71bab6a82f147ad96b3eadb2a8f34f4 P dac61d7a319d49bc85d5c6f734ccc26e: Deleting log segment in path: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515622168709-19292-0/minicluster-data/ts-0-root/wals/e71bab6a82f147ad96b3eadb2a8f34f4/wal-000000018 (ops 86-90)
I20260812 06:20:30.384043 19633 log.cc:1079] T e71bab6a82f147ad96b3eadb2a8f34f4 P dac61d7a319d49bc85d5c6f734ccc26e: Deleting log segment in path: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515622168709-19292-0/minicluster-data/ts-0-root/wals/e71bab6a82f147ad96b3eadb2a8f34f4/wal-000000019 (ops 91-94)
I20260812 06:20:30.384071 19633 log.cc:1079] T e71bab6a82f147ad96b3eadb2a8f34f4 P dac61d7a319d49bc85d5c6f734ccc26e: Deleting log segment in path: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515622168709-19292-0/minicluster-data/ts-0-root/wals/e71bab6a82f147ad96b3eadb2a8f34f4/wal-000000020 (ops 95-99)
I20260812 06:20:30.384102 19633 log.cc:1079] T e71bab6a82f147ad96b3eadb2a8f34f4 P dac61d7a319d49bc85d5c6f734ccc26e: Deleting log segment in path: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515622168709-19292-0/minicluster-data/ts-0-root/wals/e71bab6a82f147ad96b3eadb2a8f34f4/wal-000000021 (ops 100-104)
I20260812 06:20:30.384133 19633 log.cc:1079] T e71bab6a82f147ad96b3eadb2a8f34f4 P dac61d7a319d49bc85d5c6f734ccc26e: Deleting log segment in path: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515622168709-19292-0/minicluster-data/ts-0-root/wals/e71bab6a82f147ad96b3eadb2a8f34f4/wal-000000022 (ops 105-109)
I20260812 06:20:30.384161 19633 log.cc:1079] T e71bab6a82f147ad96b3eadb2a8f34f4 P dac61d7a319d49bc85d5c6f734ccc26e: Deleting log segment in path: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515622168709-19292-0/minicluster-data/ts-0-root/wals/e71bab6a82f147ad96b3eadb2a8f34f4/wal-000000023 (ops 110-114)
I20260812 06:20:30.384189 19633 log.cc:1079] T e71bab6a82f147ad96b3eadb2a8f34f4 P dac61d7a319d49bc85d5c6f734ccc26e: Deleting log segment in path: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515622168709-19292-0/minicluster-data/ts-0-root/wals/e71bab6a82f147ad96b3eadb2a8f34f4/wal-000000024 (ops 115-119)
I20260812 06:20:30.384217 19633 log.cc:1079] T e71bab6a82f147ad96b3eadb2a8f34f4 P dac61d7a319d49bc85d5c6f734ccc26e: Deleting log segment in path: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515622168709-19292-0/minicluster-data/ts-0-root/wals/e71bab6a82f147ad96b3eadb2a8f34f4/wal-000000025 (ops 120-124)
I20260812 06:20:30.384248 19633 log.cc:1079] T e71bab6a82f147ad96b3eadb2a8f34f4 P dac61d7a319d49bc85d5c6f734ccc26e: Deleting log segment in path: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515622168709-19292-0/minicluster-data/ts-0-root/wals/e71bab6a82f147ad96b3eadb2a8f34f4/wal-000000026 (ops 125-128)
I20260812 06:20:30.411607 19633 maintenance_manager.cc:643] P dac61d7a319d49bc85d5c6f734ccc26e: LogGCOp(e71bab6a82f147ad96b3eadb2a8f34f4) complete. Timing: real 0.028s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:20:30.412056 19707 maintenance_manager.cc:419] P dac61d7a319d49bc85d5c6f734ccc26e: Scheduling FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4): perf score=3.181125
I20260812 06:20:30.439934 19633 maintenance_manager.cc:643] P dac61d7a319d49bc85d5c6f734ccc26e: FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4) complete. Timing: real 0.028s	user 0.011s	sys 0.013s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":6838,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:30.440409 19707 maintenance_manager.cc:419] P dac61d7a319d49bc85d5c6f734ccc26e: Scheduling UndoDeltaBlockGCOp(e71bab6a82f147ad96b3eadb2a8f34f4): 482 bytes on disk
I20260812 06:20:30.440837 19633 maintenance_manager.cc:643] P dac61d7a319d49bc85d5c6f734ccc26e: UndoDeltaBlockGCOp(e71bab6a82f147ad96b3eadb2a8f34f4) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":57,"lbm_reads_lt_1ms":4}
I20260812 06:20:30.441386 19707 maintenance_manager.cc:419] P dac61d7a319d49bc85d5c6f734ccc26e: Scheduling FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4): perf score=2.188937
I20260812 06:20:30.450760 19633 maintenance_manager.cc:643] P dac61d7a319d49bc85d5c6f734ccc26e: FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4) complete. Timing: real 0.009s	user 0.002s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3433,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:30.451206 19707 maintenance_manager.cc:419] P dac61d7a319d49bc85d5c6f734ccc26e: Scheduling MajorDeltaCompactionOp(e71bab6a82f147ad96b3eadb2a8f34f4): perf score=1.000000
I20260812 06:20:30.672782 19633 maintenance_manager.cc:643] P dac61d7a319d49bc85d5c6f734ccc26e: MajorDeltaCompactionOp(e71bab6a82f147ad96b3eadb2a8f34f4) complete. Timing: real 0.221s	user 0.143s	sys 0.076s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":33020842,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":2642,"lbm_read_time_us":14830,"lbm_reads_lt_1ms":775,"lbm_write_time_us":37334,"lbm_writes_lt_1ms":743,"mutex_wait_us":294,"peak_mem_usage":87969044,"reinsert_count":0,"thread_start_us":82,"threads_started":1,"update_count":3500}
I20260812 06:20:30.673401 19707 maintenance_manager.cc:419] P dac61d7a319d49bc85d5c6f734ccc26e: Scheduling FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4): perf score=15.087375
I20260812 06:20:30.730533 19633 maintenance_manager.cc:643] P dac61d7a319d49bc85d5c6f734ccc26e: FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4) complete. Timing: real 0.057s	user 0.032s	sys 0.024s Metrics: {"bytes_written":16820143,"delete_count":0,"lbm_write_time_us":20791,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:20:30.731215 19707 maintenance_manager.cc:419] P dac61d7a319d49bc85d5c6f734ccc26e: Scheduling FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4): perf score=2.188937
I20260812 06:20:30.745070 19633 maintenance_manager.cc:643] P dac61d7a319d49bc85d5c6f734ccc26e: FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4) complete. Timing: real 0.014s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4093,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:30.745591 19707 maintenance_manager.cc:419] P dac61d7a319d49bc85d5c6f734ccc26e: Scheduling MajorDeltaCompactionOp(e71bab6a82f147ad96b3eadb2a8f34f4): perf score=1.000000
I20260812 06:20:30.923322 19633 maintenance_manager.cc:643] P dac61d7a319d49bc85d5c6f734ccc26e: MajorDeltaCompactionOp(e71bab6a82f147ad96b3eadb2a8f34f4) complete. Timing: real 0.178s	user 0.136s	sys 0.041s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815671,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":263,"lbm_read_time_us":10497,"lbm_reads_lt_1ms":564,"lbm_write_time_us":30411,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:20:30.923951 19707 maintenance_manager.cc:419] P dac61d7a319d49bc85d5c6f734ccc26e: Scheduling FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4): perf score=14.095187
I20260812 06:20:30.971302 19633 maintenance_manager.cc:643] P dac61d7a319d49bc85d5c6f734ccc26e: FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4) complete. Timing: real 0.047s	user 0.023s	sys 0.022s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":15753,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:30.971889 19707 maintenance_manager.cc:419] P dac61d7a319d49bc85d5c6f734ccc26e: Scheduling FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4): perf score=2.188937
I20260812 06:20:30.982285 19633 maintenance_manager.cc:643] P dac61d7a319d49bc85d5c6f734ccc26e: FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3900,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:30.982736 19707 maintenance_manager.cc:419] P dac61d7a319d49bc85d5c6f734ccc26e: Scheduling MajorDeltaCompactionOp(e71bab6a82f147ad96b3eadb2a8f34f4): perf score=1.000000
I20260812 06:20:31.158160 19633 maintenance_manager.cc:643] P dac61d7a319d49bc85d5c6f734ccc26e: MajorDeltaCompactionOp(e71bab6a82f147ad96b3eadb2a8f34f4) complete. Timing: real 0.175s	user 0.127s	sys 0.047s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1013,"lbm_read_time_us":12557,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27434,"lbm_writes_lt_1ms":543,"mutex_wait_us":284,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6784,"update_count":2500}
I20260812 06:20:31.158898 19707 maintenance_manager.cc:419] P dac61d7a319d49bc85d5c6f734ccc26e: Scheduling FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4): perf score=11.118625
I20260812 06:20:31.191138 19633 maintenance_manager.cc:643] P dac61d7a319d49bc85d5c6f734ccc26e: FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4) complete. Timing: real 0.032s	user 0.018s	sys 0.012s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":14616,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:20:31.191793 19707 maintenance_manager.cc:419] P dac61d7a319d49bc85d5c6f734ccc26e: Scheduling FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4): perf score=2.188937
I20260812 06:20:31.223897 19633 maintenance_manager.cc:643] P dac61d7a319d49bc85d5c6f734ccc26e: FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4) complete. Timing: real 0.032s	user 0.002s	sys 0.023s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6299,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:31.224437 19707 maintenance_manager.cc:419] P dac61d7a319d49bc85d5c6f734ccc26e: Scheduling FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4): perf score=2.188937
I20260812 06:20:31.234788 19633 maintenance_manager.cc:643] P dac61d7a319d49bc85d5c6f734ccc26e: FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4) complete. Timing: real 0.010s	user 0.000s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3851,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:31.235237 19707 maintenance_manager.cc:419] P dac61d7a319d49bc85d5c6f734ccc26e: Scheduling MajorDeltaCompactionOp(e71bab6a82f147ad96b3eadb2a8f34f4): perf score=1.000000
I20260812 06:20:31.403092 19633 maintenance_manager.cc:643] P dac61d7a319d49bc85d5c6f734ccc26e: MajorDeltaCompactionOp(e71bab6a82f147ad96b3eadb2a8f34f4) complete. Timing: real 0.168s	user 0.098s	sys 0.063s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815794,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":199,"lbm_read_time_us":11481,"lbm_reads_lt_1ms":573,"lbm_write_time_us":26394,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:20:31.403716 19707 maintenance_manager.cc:419] P dac61d7a319d49bc85d5c6f734ccc26e: Scheduling FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4): perf score=14.095187
I20260812 06:20:31.447192 19633 maintenance_manager.cc:643] P dac61d7a319d49bc85d5c6f734ccc26e: FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4) complete. Timing: real 0.043s	user 0.022s	sys 0.015s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":16473,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:31.447706 19707 maintenance_manager.cc:419] P dac61d7a319d49bc85d5c6f734ccc26e: Scheduling FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4): perf score=2.188937
I20260812 06:20:31.463436 19633 maintenance_manager.cc:643] P dac61d7a319d49bc85d5c6f734ccc26e: FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4) complete. Timing: real 0.016s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5891,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:31.464108 19707 maintenance_manager.cc:419] P dac61d7a319d49bc85d5c6f734ccc26e: Scheduling MajorDeltaCompactionOp(e71bab6a82f147ad96b3eadb2a8f34f4): perf score=1.000000
I20260812 06:20:31.634440 19633 maintenance_manager.cc:643] P dac61d7a319d49bc85d5c6f734ccc26e: MajorDeltaCompactionOp(e71bab6a82f147ad96b3eadb2a8f34f4) complete. Timing: real 0.170s	user 0.111s	sys 0.051s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":950,"lbm_read_time_us":10984,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25152,"lbm_writes_lt_1ms":543,"mutex_wait_us":268,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":2500}
I20260812 06:20:31.634930 19707 maintenance_manager.cc:419] P dac61d7a319d49bc85d5c6f734ccc26e: Scheduling FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4): perf score=14.095187
I20260812 06:20:31.681052 19633 maintenance_manager.cc:643] P dac61d7a319d49bc85d5c6f734ccc26e: FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4) complete. Timing: real 0.046s	user 0.022s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19595,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:31.681584 19707 maintenance_manager.cc:419] P dac61d7a319d49bc85d5c6f734ccc26e: Scheduling FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4): perf score=2.188937
I20260812 06:20:31.700461 19633 maintenance_manager.cc:643] P dac61d7a319d49bc85d5c6f734ccc26e: FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4) complete. Timing: real 0.019s	user 0.011s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4869,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:31.701017 19707 maintenance_manager.cc:419] P dac61d7a319d49bc85d5c6f734ccc26e: Scheduling FlushMRSOp(e71bab6a82f147ad96b3eadb2a8f34f4): perf score=1.000000
I20260812 06:20:31.739295 19633 maintenance_manager.cc:643] P dac61d7a319d49bc85d5c6f734ccc26e: FlushMRSOp(e71bab6a82f147ad96b3eadb2a8f34f4) complete. Timing: real 0.038s	user 0.023s	sys 0.000s Metrics: {"bytes_written":1152510,"cfile_init":1,"dirs.queue_time_us":43,"dirs.run_cpu_time_us":210,"dirs.run_wall_time_us":1339,"drs_written":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1405,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:20:31.740252 19707 maintenance_manager.cc:419] P dac61d7a319d49bc85d5c6f734ccc26e: Scheduling UndoDeltaBlockGCOp(e71bab6a82f147ad96b3eadb2a8f34f4): 447 bytes on disk
I20260812 06:20:31.740800 19633 maintenance_manager.cc:643] P dac61d7a319d49bc85d5c6f734ccc26e: UndoDeltaBlockGCOp(e71bab6a82f147ad96b3eadb2a8f34f4) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":85,"lbm_reads_lt_1ms":4}
I20260812 06:20:31.741519 19707 maintenance_manager.cc:419] P dac61d7a319d49bc85d5c6f734ccc26e: Scheduling FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4): perf score=3.181125
I20260812 06:20:31.758163 19633 maintenance_manager.cc:643] P dac61d7a319d49bc85d5c6f734ccc26e: FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4) complete. Timing: real 0.016s	user 0.001s	sys 0.013s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":5711,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:31.758625 19707 maintenance_manager.cc:419] P dac61d7a319d49bc85d5c6f734ccc26e: Scheduling LogGCOp(e71bab6a82f147ad96b3eadb2a8f34f4): free 112692608 bytes of WAL
I20260812 06:20:31.758836 19633 log_reader.cc:385] T e71bab6a82f147ad96b3eadb2a8f34f4: removed 11 log segments from log reader
I20260812 06:20:31.758879 19633 log.cc:1079] T e71bab6a82f147ad96b3eadb2a8f34f4 P dac61d7a319d49bc85d5c6f734ccc26e: Deleting log segment in path: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515622168709-19292-0/minicluster-data/ts-0-root/wals/e71bab6a82f147ad96b3eadb2a8f34f4/wal-000000027 (ops 129-133)
I20260812 06:20:31.758908 19633 log.cc:1079] T e71bab6a82f147ad96b3eadb2a8f34f4 P dac61d7a319d49bc85d5c6f734ccc26e: Deleting log segment in path: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515622168709-19292-0/minicluster-data/ts-0-root/wals/e71bab6a82f147ad96b3eadb2a8f34f4/wal-000000028 (ops 134-138)
I20260812 06:20:31.758934 19633 log.cc:1079] T e71bab6a82f147ad96b3eadb2a8f34f4 P dac61d7a319d49bc85d5c6f734ccc26e: Deleting log segment in path: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515622168709-19292-0/minicluster-data/ts-0-root/wals/e71bab6a82f147ad96b3eadb2a8f34f4/wal-000000029 (ops 139-143)
I20260812 06:20:31.758957 19633 log.cc:1079] T e71bab6a82f147ad96b3eadb2a8f34f4 P dac61d7a319d49bc85d5c6f734ccc26e: Deleting log segment in path: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515622168709-19292-0/minicluster-data/ts-0-root/wals/e71bab6a82f147ad96b3eadb2a8f34f4/wal-000000030 (ops 144-148)
I20260812 06:20:31.758978 19633 log.cc:1079] T e71bab6a82f147ad96b3eadb2a8f34f4 P dac61d7a319d49bc85d5c6f734ccc26e: Deleting log segment in path: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515622168709-19292-0/minicluster-data/ts-0-root/wals/e71bab6a82f147ad96b3eadb2a8f34f4/wal-000000031 (ops 149-153)
I20260812 06:20:31.759014 19633 log.cc:1079] T e71bab6a82f147ad96b3eadb2a8f34f4 P dac61d7a319d49bc85d5c6f734ccc26e: Deleting log segment in path: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515622168709-19292-0/minicluster-data/ts-0-root/wals/e71bab6a82f147ad96b3eadb2a8f34f4/wal-000000032 (ops 154-158)
I20260812 06:20:31.759047 19633 log.cc:1079] T e71bab6a82f147ad96b3eadb2a8f34f4 P dac61d7a319d49bc85d5c6f734ccc26e: Deleting log segment in path: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515622168709-19292-0/minicluster-data/ts-0-root/wals/e71bab6a82f147ad96b3eadb2a8f34f4/wal-000000033 (ops 159-163)
I20260812 06:20:31.759076 19633 log.cc:1079] T e71bab6a82f147ad96b3eadb2a8f34f4 P dac61d7a319d49bc85d5c6f734ccc26e: Deleting log segment in path: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515622168709-19292-0/minicluster-data/ts-0-root/wals/e71bab6a82f147ad96b3eadb2a8f34f4/wal-000000034 (ops 164-168)
I20260812 06:20:31.759105 19633 log.cc:1079] T e71bab6a82f147ad96b3eadb2a8f34f4 P dac61d7a319d49bc85d5c6f734ccc26e: Deleting log segment in path: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515622168709-19292-0/minicluster-data/ts-0-root/wals/e71bab6a82f147ad96b3eadb2a8f34f4/wal-000000035 (ops 169-173)
I20260812 06:20:31.759135 19633 log.cc:1079] T e71bab6a82f147ad96b3eadb2a8f34f4 P dac61d7a319d49bc85d5c6f734ccc26e: Deleting log segment in path: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515622168709-19292-0/minicluster-data/ts-0-root/wals/e71bab6a82f147ad96b3eadb2a8f34f4/wal-000000036 (ops 174-178)
I20260812 06:20:31.759164 19633 log.cc:1079] T e71bab6a82f147ad96b3eadb2a8f34f4 P dac61d7a319d49bc85d5c6f734ccc26e: Deleting log segment in path: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515622168709-19292-0/minicluster-data/ts-0-root/wals/e71bab6a82f147ad96b3eadb2a8f34f4/wal-000000037 (ops 179-183)
I20260812 06:20:31.781344 19633 maintenance_manager.cc:643] P dac61d7a319d49bc85d5c6f734ccc26e: LogGCOp(e71bab6a82f147ad96b3eadb2a8f34f4) complete. Timing: real 0.023s	user 0.000s	sys 0.020s Metrics: {}
I20260812 06:20:31.781852 19707 maintenance_manager.cc:419] P dac61d7a319d49bc85d5c6f734ccc26e: Scheduling FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4): perf score=2.188937
I20260812 06:20:31.804584 19633 maintenance_manager.cc:643] P dac61d7a319d49bc85d5c6f734ccc26e: FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4) complete. Timing: real 0.023s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5174,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:31.805071 19707 maintenance_manager.cc:419] P dac61d7a319d49bc85d5c6f734ccc26e: Scheduling LogGCOp(e71bab6a82f147ad96b3eadb2a8f34f4): free 12017954 bytes of WAL
I20260812 06:20:31.805284 19633 log_reader.cc:385] T e71bab6a82f147ad96b3eadb2a8f34f4: removed 1 log segments from log reader
I20260812 06:20:31.805330 19633 log.cc:1079] T e71bab6a82f147ad96b3eadb2a8f34f4 P dac61d7a319d49bc85d5c6f734ccc26e: Deleting log segment in path: /tmp/dist-test-tasknrIn2Q/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515622168709-19292-0/minicluster-data/ts-0-root/wals/e71bab6a82f147ad96b3eadb2a8f34f4/wal-000000038 (ops 184-188)
I20260812 06:20:31.807193 19633 maintenance_manager.cc:643] P dac61d7a319d49bc85d5c6f734ccc26e: LogGCOp(e71bab6a82f147ad96b3eadb2a8f34f4) complete. Timing: real 0.002s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:20:31.807502 19707 maintenance_manager.cc:419] P dac61d7a319d49bc85d5c6f734ccc26e: Scheduling FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4): perf score=2.188937
I20260812 06:20:31.818238 19633 maintenance_manager.cc:643] P dac61d7a319d49bc85d5c6f734ccc26e: FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3681,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:31.818689 19707 maintenance_manager.cc:419] P dac61d7a319d49bc85d5c6f734ccc26e: Scheduling MajorDeltaCompactionOp(e71bab6a82f147ad96b3eadb2a8f34f4): perf score=1.000000
I20260812 06:20:32.061316 19633 maintenance_manager.cc:643] P dac61d7a319d49bc85d5c6f734ccc26e: MajorDeltaCompactionOp(e71bab6a82f147ad96b3eadb2a8f34f4) complete. Timing: real 0.242s	user 0.164s	sys 0.075s Metrics: {"cfile_cache_miss":835,"cfile_cache_miss_bytes":37123263,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":3695,"lbm_read_time_us":17504,"lbm_reads_lt_1ms":875,"lbm_write_time_us":41093,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":842,"mutex_wait_us":1598,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":1280,"thread_start_us":136,"threads_started":1,"update_count":4000}
I20260812 06:20:32.061939 19707 maintenance_manager.cc:419] P dac61d7a319d49bc85d5c6f734ccc26e: Scheduling FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4): perf score=18.063937
I20260812 06:20:32.107517 19292 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.641s	user 1.728s	sys 0.136s
I20260812 06:20:32.127137 19633 maintenance_manager.cc:643] P dac61d7a319d49bc85d5c6f734ccc26e: FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4) complete. Timing: real 0.065s	user 0.036s	sys 0.026s Metrics: {"bytes_written":20512320,"delete_count":0,"lbm_write_time_us":26946,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":502,"reinsert_count":0,"update_count":2500}
I20260812 06:20:32.127627 19707 maintenance_manager.cc:419] P dac61d7a319d49bc85d5c6f734ccc26e: Scheduling FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4): perf score=2.188937
I20260812 06:20:32.131682 19292 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.024s	user 0.001s	sys 0.000s
I20260812 06:20:32.132151 19292 tablet_server.cc:179] TabletServer@127.18.215.1:0 shutting down...
I20260812 06:20:32.140173 19633 maintenance_manager.cc:643] P dac61d7a319d49bc85d5c6f734ccc26e: FlushDeltaMemStoresOp(e71bab6a82f147ad96b3eadb2a8f34f4) complete. Timing: real 0.012s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4855,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:32.140594 19292 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:32.140776 19292 tablet_replica.cc:333] T e71bab6a82f147ad96b3eadb2a8f34f4 P dac61d7a319d49bc85d5c6f734ccc26e: stopping tablet replica
I20260812 06:20:32.140904 19292 raft_consensus.cc:2243] T e71bab6a82f147ad96b3eadb2a8f34f4 P dac61d7a319d49bc85d5c6f734ccc26e [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:32.141074 19292 raft_consensus.cc:2272] T e71bab6a82f147ad96b3eadb2a8f34f4 P dac61d7a319d49bc85d5c6f734ccc26e [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:32.154100 19292 tablet_server.cc:196] TabletServer@127.18.215.1:0 shutdown complete.
I20260812 06:20:32.156836 19292 master.cc:562] Master@127.18.215.62:41241 shutting down...
I20260812 06:20:32.159843 19292 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 120eaf043fef430ebfd6f1afc8dd4ca7 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:32.160006 19292 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 120eaf043fef430ebfd6f1afc8dd4ca7 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:32.160073 19292 tablet_replica.cc:333] T 00000000000000000000000000000000 P 120eaf043fef430ebfd6f1afc8dd4ca7: stopping tablet replica
I20260812 06:20:32.172091 19292 master.cc:584] Master@127.18.215.62:41241 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (4960 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10062 ms total)

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