[==========] 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:18:32.196358 11613 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.11.87.126:42045
I20260812 06:18:32.197431 11613 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:18:32.198001 11613 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:32.204262 11622 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:18:32.204316 11625 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:18:32.204447 11613 server_base.cc:1061] running on GCE node
W20260812 06:18:32.204573 11620 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:18:32.205067 11613 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:32.205196 11613 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:18:32.205242 11613 hybrid_clock.cc:648] HybridClock initialized: now 1786515512205239 us; error 0 us; skew 500 ppm
I20260812 06:18:32.207261 11613 webserver.cc:533] Webserver started at http://127.11.87.126:45357/ using document root <none> and password file <none>
I20260812 06:18:32.207877 11613 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:32.207949 11613 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:32.208237 11613 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:32.210462 11613 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515512185349-11613-0/minicluster-data/master-0-root/instance:
uuid: "19f7c91b400e4b5093f7ceac4aaa2ea1"
format_stamp: "Formatted at 2026-08-12 06:18:32 on dist-test-slave-vq2q"
I20260812 06:18:32.218194 11613 fs_manager.cc:696] Time spent creating directory manager: real 0.007s	user 0.003s	sys 0.000s
I20260812 06:18:32.221101 11632 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:18:32.222455 11613 fs_manager.cc:730] Time spent opening block manager: real 0.003s	user 0.002s	sys 0.001s
I20260812 06:18:32.222579 11613 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515512185349-11613-0/minicluster-data/master-0-root
uuid: "19f7c91b400e4b5093f7ceac4aaa2ea1"
format_stamp: "Formatted at 2026-08-12 06:18:32 on dist-test-slave-vq2q"
I20260812 06:18:32.222723 11613 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515512185349-11613-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515512185349-11613-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515512185349-11613-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:18:32.242689 11613 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:32.243381 11613 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:18:32.243523 11613 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:32.252022 11695 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.11.87.126:42045 every 8 connection(s)
I20260812 06:18:32.252030 11613 rpc_server.cc:307] RPC server started. Bound to: 127.11.87.126:42045
I20260812 06:18:32.254467 11696 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:18:32.259831 11696 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 19f7c91b400e4b5093f7ceac4aaa2ea1: Bootstrap starting.
I20260812 06:18:32.262663 11696 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 19f7c91b400e4b5093f7ceac4aaa2ea1: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:32.263811 11696 log.cc:826] T 00000000000000000000000000000000 P 19f7c91b400e4b5093f7ceac4aaa2ea1: Log is configured to *not* fsync() on all Append() calls
I20260812 06:18:32.265890 11696 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 19f7c91b400e4b5093f7ceac4aaa2ea1: No bootstrap required, opened a new log
I20260812 06:18:32.269754 11696 raft_consensus.cc:359] T 00000000000000000000000000000000 P 19f7c91b400e4b5093f7ceac4aaa2ea1 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "19f7c91b400e4b5093f7ceac4aaa2ea1" member_type: VOTER }
I20260812 06:18:32.269966 11696 raft_consensus.cc:385] T 00000000000000000000000000000000 P 19f7c91b400e4b5093f7ceac4aaa2ea1 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:32.270052 11696 raft_consensus.cc:740] T 00000000000000000000000000000000 P 19f7c91b400e4b5093f7ceac4aaa2ea1 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 19f7c91b400e4b5093f7ceac4aaa2ea1, State: Initialized, Role: FOLLOWER
I20260812 06:18:32.270766 11696 consensus_queue.cc:260] T 00000000000000000000000000000000 P 19f7c91b400e4b5093f7ceac4aaa2ea1 [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: "19f7c91b400e4b5093f7ceac4aaa2ea1" member_type: VOTER }
I20260812 06:18:32.270948 11696 raft_consensus.cc:399] T 00000000000000000000000000000000 P 19f7c91b400e4b5093f7ceac4aaa2ea1 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:32.271019 11696 raft_consensus.cc:493] T 00000000000000000000000000000000 P 19f7c91b400e4b5093f7ceac4aaa2ea1 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:32.271133 11696 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 19f7c91b400e4b5093f7ceac4aaa2ea1 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:32.272135 11696 raft_consensus.cc:515] T 00000000000000000000000000000000 P 19f7c91b400e4b5093f7ceac4aaa2ea1 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "19f7c91b400e4b5093f7ceac4aaa2ea1" member_type: VOTER }
I20260812 06:18:32.272635 11696 leader_election.cc:304] T 00000000000000000000000000000000 P 19f7c91b400e4b5093f7ceac4aaa2ea1 [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: 19f7c91b400e4b5093f7ceac4aaa2ea1; no voters: 
I20260812 06:18:32.272990 11696 leader_election.cc:290] T 00000000000000000000000000000000 P 19f7c91b400e4b5093f7ceac4aaa2ea1 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:32.273082 11699 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 19f7c91b400e4b5093f7ceac4aaa2ea1 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:32.273350 11699 raft_consensus.cc:697] T 00000000000000000000000000000000 P 19f7c91b400e4b5093f7ceac4aaa2ea1 [term 1 LEADER]: Becoming Leader. State: Replica: 19f7c91b400e4b5093f7ceac4aaa2ea1, State: Running, Role: LEADER
I20260812 06:18:32.273754 11699 consensus_queue.cc:237] T 00000000000000000000000000000000 P 19f7c91b400e4b5093f7ceac4aaa2ea1 [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: "19f7c91b400e4b5093f7ceac4aaa2ea1" member_type: VOTER }
I20260812 06:18:32.274122 11696 sys_catalog.cc:565] T 00000000000000000000000000000000 P 19f7c91b400e4b5093f7ceac4aaa2ea1 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:32.275532 11700 sys_catalog.cc:455] T 00000000000000000000000000000000 P 19f7c91b400e4b5093f7ceac4aaa2ea1 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "19f7c91b400e4b5093f7ceac4aaa2ea1" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "19f7c91b400e4b5093f7ceac4aaa2ea1" member_type: VOTER } }
I20260812 06:18:32.275653 11700 sys_catalog.cc:458] T 00000000000000000000000000000000 P 19f7c91b400e4b5093f7ceac4aaa2ea1 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:32.275959 11701 sys_catalog.cc:455] T 00000000000000000000000000000000 P 19f7c91b400e4b5093f7ceac4aaa2ea1 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 19f7c91b400e4b5093f7ceac4aaa2ea1. Latest consensus state: current_term: 1 leader_uuid: "19f7c91b400e4b5093f7ceac4aaa2ea1" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "19f7c91b400e4b5093f7ceac4aaa2ea1" member_type: VOTER } }
I20260812 06:18:32.276017 11709 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:32.276036 11701 sys_catalog.cc:458] T 00000000000000000000000000000000 P 19f7c91b400e4b5093f7ceac4aaa2ea1 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:32.278708 11709 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:32.278959 11613 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:32.283998 11709 catalog_manager.cc:1383] Generated new cluster ID: 331748d301954ee6bf0de2d9f3819020
I20260812 06:18:32.284057 11709 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:32.300349 11709 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:32.301573 11709 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:32.313336 11709 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 19f7c91b400e4b5093f7ceac4aaa2ea1: Generated new TSK 0
I20260812 06:18:32.314107 11709 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:32.346379 11613 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:32.349352 11724 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:18:32.349360 11721 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:18:32.349360 11722 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:18:32.349850 11613 server_base.cc:1061] running on GCE node
I20260812 06:18:32.350045 11613 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:32.350091 11613 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:18:32.350113 11613 hybrid_clock.cc:648] HybridClock initialized: now 1786515512350113 us; error 0 us; skew 500 ppm
I20260812 06:18:32.351052 11613 webserver.cc:533] Webserver started at http://127.11.87.65:41969/ using document root <none> and password file <none>
I20260812 06:18:32.351227 11613 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:32.351284 11613 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:32.351385 11613 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:32.351814 11613 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515512185349-11613-0/minicluster-data/ts-0-root/instance:
uuid: "ea041e63be0642dcbbaad383994a116d"
format_stamp: "Formatted at 2026-08-12 06:18:32 on dist-test-slave-vq2q"
I20260812 06:18:32.353694 11613 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:32.354884 11730 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:18:32.355167 11613 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:32.355247 11613 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515512185349-11613-0/minicluster-data/ts-0-root
uuid: "ea041e63be0642dcbbaad383994a116d"
format_stamp: "Formatted at 2026-08-12 06:18:32 on dist-test-slave-vq2q"
I20260812 06:18:32.355324 11613 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515512185349-11613-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515512185349-11613-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515512185349-11613-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:18:32.376245 11613 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:32.376787 11613 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:32.377418 11613 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:32.378510 11613 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:32.378580 11613 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:32.378648 11613 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:32.378679 11613 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:32.385604 11613 rpc_server.cc:307] RPC server started. Bound to: 127.11.87.65:35889
I20260812 06:18:32.385653 11810 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.11.87.65:35889 every 8 connection(s)
I20260812 06:18:32.400514 11811 heartbeater.cc:344] Connected to a master server at 127.11.87.126:42045
I20260812 06:18:32.400782 11811 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:32.401285 11811 heartbeater.cc:507] Master 127.11.87.126:42045 requested a full tablet report, sending...
I20260812 06:18:32.402781 11652 ts_manager.cc:194] Registered new tserver with Master: ea041e63be0642dcbbaad383994a116d (127.11.87.65:35889)
I20260812 06:18:32.403504 11613 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.017097882s
I20260812 06:18:32.404189 11652 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:55878
I20260812 06:18:32.413416 11652 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:55886:
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:18:32.428093 11767 tablet_service.cc:1511] Processing CreateTablet for tablet d889d570fa5445c1bf536ce92b6e266a (DEFAULT_TABLE table=heavy-update-compaction-test [id=e6085dcfa7d841a2a9cfe133e5ed7807]), partition=
I20260812 06:18:32.428563 11767 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet d889d570fa5445c1bf536ce92b6e266a. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:32.431622 11826 tablet_bootstrap.cc:492] T d889d570fa5445c1bf536ce92b6e266a P ea041e63be0642dcbbaad383994a116d: Bootstrap starting.
I20260812 06:18:32.432485 11826 tablet_bootstrap.cc:654] T d889d570fa5445c1bf536ce92b6e266a P ea041e63be0642dcbbaad383994a116d: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:32.433916 11826 tablet_bootstrap.cc:492] T d889d570fa5445c1bf536ce92b6e266a P ea041e63be0642dcbbaad383994a116d: No bootstrap required, opened a new log
I20260812 06:18:32.434016 11826 ts_tablet_manager.cc:1403] T d889d570fa5445c1bf536ce92b6e266a P ea041e63be0642dcbbaad383994a116d: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:32.434473 11826 raft_consensus.cc:359] T d889d570fa5445c1bf536ce92b6e266a P ea041e63be0642dcbbaad383994a116d [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ea041e63be0642dcbbaad383994a116d" member_type: VOTER last_known_addr { host: "127.11.87.65" port: 35889 } }
I20260812 06:18:32.434576 11826 raft_consensus.cc:385] T d889d570fa5445c1bf536ce92b6e266a P ea041e63be0642dcbbaad383994a116d [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:32.434608 11826 raft_consensus.cc:740] T d889d570fa5445c1bf536ce92b6e266a P ea041e63be0642dcbbaad383994a116d [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: ea041e63be0642dcbbaad383994a116d, State: Initialized, Role: FOLLOWER
I20260812 06:18:32.434748 11826 consensus_queue.cc:260] T d889d570fa5445c1bf536ce92b6e266a P ea041e63be0642dcbbaad383994a116d [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: "ea041e63be0642dcbbaad383994a116d" member_type: VOTER last_known_addr { host: "127.11.87.65" port: 35889 } }
I20260812 06:18:32.434864 11826 raft_consensus.cc:399] T d889d570fa5445c1bf536ce92b6e266a P ea041e63be0642dcbbaad383994a116d [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:32.434921 11826 raft_consensus.cc:493] T d889d570fa5445c1bf536ce92b6e266a P ea041e63be0642dcbbaad383994a116d [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:32.434964 11826 raft_consensus.cc:3060] T d889d570fa5445c1bf536ce92b6e266a P ea041e63be0642dcbbaad383994a116d [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:32.435765 11826 raft_consensus.cc:515] T d889d570fa5445c1bf536ce92b6e266a P ea041e63be0642dcbbaad383994a116d [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ea041e63be0642dcbbaad383994a116d" member_type: VOTER last_known_addr { host: "127.11.87.65" port: 35889 } }
I20260812 06:18:32.435890 11826 leader_election.cc:304] T d889d570fa5445c1bf536ce92b6e266a P ea041e63be0642dcbbaad383994a116d [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: ea041e63be0642dcbbaad383994a116d; no voters: 
I20260812 06:18:32.436080 11826 leader_election.cc:290] T d889d570fa5445c1bf536ce92b6e266a P ea041e63be0642dcbbaad383994a116d [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:32.436199 11828 raft_consensus.cc:2804] T d889d570fa5445c1bf536ce92b6e266a P ea041e63be0642dcbbaad383994a116d [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:32.436398 11828 raft_consensus.cc:697] T d889d570fa5445c1bf536ce92b6e266a P ea041e63be0642dcbbaad383994a116d [term 1 LEADER]: Becoming Leader. State: Replica: ea041e63be0642dcbbaad383994a116d, State: Running, Role: LEADER
I20260812 06:18:32.436539 11826 ts_tablet_manager.cc:1434] T d889d570fa5445c1bf536ce92b6e266a P ea041e63be0642dcbbaad383994a116d: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:18:32.436741 11811 heartbeater.cc:499] Master 127.11.87.126:42045 was elected leader, sending a full tablet report...
I20260812 06:18:32.436566 11828 consensus_queue.cc:237] T d889d570fa5445c1bf536ce92b6e266a P ea041e63be0642dcbbaad383994a116d [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: "ea041e63be0642dcbbaad383994a116d" member_type: VOTER last_known_addr { host: "127.11.87.65" port: 35889 } }
I20260812 06:18:32.439850 11652 catalog_manager.cc:5719] T d889d570fa5445c1bf536ce92b6e266a P ea041e63be0642dcbbaad383994a116d reported cstate change: term changed from 0 to 1, leader changed from <none> to ea041e63be0642dcbbaad383994a116d (127.11.87.65). New cstate: current_term: 1 leader_uuid: "ea041e63be0642dcbbaad383994a116d" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ea041e63be0642dcbbaad383994a116d" member_type: VOTER last_known_addr { host: "127.11.87.65" port: 35889 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:32.510672 11613 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.063s	user 0.023s	sys 0.007s
I20260812 06:18:32.637147 11812 maintenance_manager.cc:419] P ea041e63be0642dcbbaad383994a116d: Scheduling FlushMRSOp(d889d570fa5445c1bf536ce92b6e266a): perf score=15.086190
I20260812 06:18:32.802073 11738 maintenance_manager.cc:643] P ea041e63be0642dcbbaad383994a116d: FlushMRSOp(d889d570fa5445c1bf536ce92b6e266a) complete. Timing: real 0.165s	user 0.129s	sys 0.025s Metrics: {"bytes_written":11897251,"cfile_init":1,"compiler_manager_pool.queue_time_us":200,"delete_count":0,"dirs.queue_time_us":49,"dirs.run_cpu_time_us":175,"dirs.run_wall_time_us":742,"drs_written":1,"lbm_read_time_us":72,"lbm_reads_lt_1ms":4,"lbm_write_time_us":36430,"lbm_writes_lt_1ms":657,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":1408,"thread_start_us":110,"threads_started":1,"update_count":1450}
I20260812 06:18:32.803457 11812 maintenance_manager.cc:419] P ea041e63be0642dcbbaad383994a116d: Scheduling LogGCOp(d889d570fa5445c1bf536ce92b6e266a): free 20743880 bytes of WAL
I20260812 06:18:32.803884 11738 log_reader.cc:385] T d889d570fa5445c1bf536ce92b6e266a: removed 2 log segments from log reader
I20260812 06:18:32.803993 11738 log.cc:1079] T d889d570fa5445c1bf536ce92b6e266a P ea041e63be0642dcbbaad383994a116d: Deleting log segment in path: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515512185349-11613-0/minicluster-data/ts-0-root/wals/d889d570fa5445c1bf536ce92b6e266a/wal-000000001 (ops 1-6)
I20260812 06:18:32.804092 11738 log.cc:1079] T d889d570fa5445c1bf536ce92b6e266a P ea041e63be0642dcbbaad383994a116d: Deleting log segment in path: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515512185349-11613-0/minicluster-data/ts-0-root/wals/d889d570fa5445c1bf536ce92b6e266a/wal-000000002 (ops 7-11)
I20260812 06:18:32.808996 11738 maintenance_manager.cc:643] P ea041e63be0642dcbbaad383994a116d: LogGCOp(d889d570fa5445c1bf536ce92b6e266a) complete. Timing: real 0.005s	user 0.001s	sys 0.004s Metrics: {}
I20260812 06:18:32.809444 11812 maintenance_manager.cc:419] P ea041e63be0642dcbbaad383994a116d: Scheduling UndoDeltaBlockGCOp(d889d570fa5445c1bf536ce92b6e266a): 12719216 bytes on disk
I20260812 06:18:32.810117 11738 maintenance_manager.cc:643] P ea041e63be0642dcbbaad383994a116d: UndoDeltaBlockGCOp(d889d570fa5445c1bf536ce92b6e266a) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":76,"lbm_reads_lt_1ms":4}
I20260812 06:18:32.810572 11812 maintenance_manager.cc:419] P ea041e63be0642dcbbaad383994a116d: Scheduling FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a): perf score=2.188937
I20260812 06:18:32.826332 11738 maintenance_manager.cc:643] P ea041e63be0642dcbbaad383994a116d: FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a) complete. Timing: real 0.016s	user 0.001s	sys 0.013s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5853,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:32.826843 11812 maintenance_manager.cc:419] P ea041e63be0642dcbbaad383994a116d: Scheduling MajorDeltaCompactionOp(d889d570fa5445c1bf536ce92b6e266a): perf score=1.000000
I20260812 06:18:32.967883 11738 maintenance_manager.cc:643] P ea041e63be0642dcbbaad383994a116d: MajorDeltaCompactionOp(d889d570fa5445c1bf536ce92b6e266a) complete. Timing: real 0.141s	user 0.109s	sys 0.029s Metrics: {"cfile_cache_miss":422,"cfile_cache_miss_bytes":20262038,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":802,"lbm_read_time_us":8729,"lbm_reads_lt_1ms":450,"lbm_write_time_us":26376,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":432,"peak_mem_usage":49238594,"reinsert_count":0,"thread_start_us":314,"threads_started":5,"update_count":1950}
I20260812 06:18:32.968395 11812 maintenance_manager.cc:419] P ea041e63be0642dcbbaad383994a116d: Scheduling FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a): perf score=10.126437
I20260812 06:18:33.010390 11738 maintenance_manager.cc:643] P ea041e63be0642dcbbaad383994a116d: FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a) complete. Timing: real 0.041s	user 0.035s	sys 0.004s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17146,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:33.010895 11812 maintenance_manager.cc:419] P ea041e63be0642dcbbaad383994a116d: Scheduling FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a): perf score=2.188937
I20260812 06:18:33.020949 11738 maintenance_manager.cc:643] P ea041e63be0642dcbbaad383994a116d: FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a) complete. Timing: real 0.010s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3505,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:33.021567 11812 maintenance_manager.cc:419] P ea041e63be0642dcbbaad383994a116d: Scheduling MajorDeltaCompactionOp(d889d570fa5445c1bf536ce92b6e266a): perf score=1.000000
I20260812 06:18:33.152629 11738 maintenance_manager.cc:643] P ea041e63be0642dcbbaad383994a116d: MajorDeltaCompactionOp(d889d570fa5445c1bf536ce92b6e266a) complete. Timing: real 0.131s	user 0.104s	sys 0.015s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":198,"lbm_read_time_us":9244,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22196,"lbm_writes_lt_1ms":443,"mutex_wait_us":2,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2816,"update_count":2000}
I20260812 06:18:33.153107 11812 maintenance_manager.cc:419] P ea041e63be0642dcbbaad383994a116d: Scheduling FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a): perf score=10.126437
I20260812 06:18:33.199031 11738 maintenance_manager.cc:643] P ea041e63be0642dcbbaad383994a116d: FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a) complete. Timing: real 0.046s	user 0.030s	sys 0.004s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":14848,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:33.199618 11812 maintenance_manager.cc:419] P ea041e63be0642dcbbaad383994a116d: Scheduling FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a): perf score=2.188937
I20260812 06:18:33.209888 11738 maintenance_manager.cc:643] P ea041e63be0642dcbbaad383994a116d: FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3768,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:33.210330 11812 maintenance_manager.cc:419] P ea041e63be0642dcbbaad383994a116d: Scheduling MajorDeltaCompactionOp(d889d570fa5445c1bf536ce92b6e266a): perf score=1.000000
I20260812 06:18:33.336828 11738 maintenance_manager.cc:643] P ea041e63be0642dcbbaad383994a116d: MajorDeltaCompactionOp(d889d570fa5445c1bf536ce92b6e266a) complete. Timing: real 0.126s	user 0.113s	sys 0.012s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":246,"lbm_read_time_us":8305,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23070,"lbm_writes_lt_1ms":443,"mutex_wait_us":51,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2000}
I20260812 06:18:33.337407 11812 maintenance_manager.cc:419] P ea041e63be0642dcbbaad383994a116d: Scheduling FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a): perf score=10.126437
I20260812 06:18:33.392030 11738 maintenance_manager.cc:643] P ea041e63be0642dcbbaad383994a116d: FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a) complete. Timing: real 0.054s	user 0.020s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14922,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:33.392767 11812 maintenance_manager.cc:419] P ea041e63be0642dcbbaad383994a116d: Scheduling FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a): perf score=2.188937
I20260812 06:18:33.408453 11738 maintenance_manager.cc:643] P ea041e63be0642dcbbaad383994a116d: FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a) complete. Timing: real 0.015s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5746,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:33.409034 11812 maintenance_manager.cc:419] P ea041e63be0642dcbbaad383994a116d: Scheduling MajorDeltaCompactionOp(d889d570fa5445c1bf536ce92b6e266a): perf score=1.000000
I20260812 06:18:33.565958 11738 maintenance_manager.cc:643] P ea041e63be0642dcbbaad383994a116d: MajorDeltaCompactionOp(d889d570fa5445c1bf536ce92b6e266a) complete. Timing: real 0.157s	user 0.092s	sys 0.060s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":499,"lbm_read_time_us":10788,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25252,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":442,"mutex_wait_us":276,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:18:33.566617 11812 maintenance_manager.cc:419] P ea041e63be0642dcbbaad383994a116d: Scheduling FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a): perf score=10.126437
I20260812 06:18:33.612845 11738 maintenance_manager.cc:643] P ea041e63be0642dcbbaad383994a116d: FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a) complete. Timing: real 0.046s	user 0.028s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19459,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:18:33.613438 11812 maintenance_manager.cc:419] P ea041e63be0642dcbbaad383994a116d: Scheduling FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a): perf score=2.188937
I20260812 06:18:33.623531 11738 maintenance_manager.cc:643] P ea041e63be0642dcbbaad383994a116d: FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3684,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:33.623929 11812 maintenance_manager.cc:419] P ea041e63be0642dcbbaad383994a116d: Scheduling MajorDeltaCompactionOp(d889d570fa5445c1bf536ce92b6e266a): perf score=1.000000
I20260812 06:18:33.763954 11738 maintenance_manager.cc:643] P ea041e63be0642dcbbaad383994a116d: MajorDeltaCompactionOp(d889d570fa5445c1bf536ce92b6e266a) complete. Timing: real 0.140s	user 0.107s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":315,"lbm_read_time_us":8556,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27617,"lbm_writes_lt_1ms":443,"mutex_wait_us":91,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:18:33.764547 11812 maintenance_manager.cc:419] P ea041e63be0642dcbbaad383994a116d: Scheduling FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a): perf score=10.126437
I20260812 06:18:33.812460 11738 maintenance_manager.cc:643] P ea041e63be0642dcbbaad383994a116d: FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a) complete. Timing: real 0.048s	user 0.022s	sys 0.011s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":15820,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:33.813000 11812 maintenance_manager.cc:419] P ea041e63be0642dcbbaad383994a116d: Scheduling FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a): perf score=2.188937
I20260812 06:18:33.825960 11738 maintenance_manager.cc:643] P ea041e63be0642dcbbaad383994a116d: FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a) complete. Timing: real 0.013s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4706,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:33.826561 11812 maintenance_manager.cc:419] P ea041e63be0642dcbbaad383994a116d: Scheduling MajorDeltaCompactionOp(d889d570fa5445c1bf536ce92b6e266a): perf score=1.000000
I20260812 06:18:33.968112 11738 maintenance_manager.cc:643] P ea041e63be0642dcbbaad383994a116d: MajorDeltaCompactionOp(d889d570fa5445c1bf536ce92b6e266a) complete. Timing: real 0.141s	user 0.122s	sys 0.012s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1034,"lbm_read_time_us":9850,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25661,"lbm_writes_lt_1ms":443,"mutex_wait_us":319,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2000}
I20260812 06:18:33.969561 11812 maintenance_manager.cc:419] P ea041e63be0642dcbbaad383994a116d: Scheduling FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a): perf score=10.126437
I20260812 06:18:34.018080 11738 maintenance_manager.cc:643] P ea041e63be0642dcbbaad383994a116d: FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a) complete. Timing: real 0.048s	user 0.027s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17952,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:34.018596 11812 maintenance_manager.cc:419] P ea041e63be0642dcbbaad383994a116d: Scheduling FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a): perf score=2.188937
I20260812 06:18:34.032537 11738 maintenance_manager.cc:643] P ea041e63be0642dcbbaad383994a116d: FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a) complete. Timing: real 0.014s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4886,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:34.033288 11812 maintenance_manager.cc:419] P ea041e63be0642dcbbaad383994a116d: Scheduling MajorDeltaCompactionOp(d889d570fa5445c1bf536ce92b6e266a): perf score=1.000000
I20260812 06:18:34.156040 11738 maintenance_manager.cc:643] P ea041e63be0642dcbbaad383994a116d: MajorDeltaCompactionOp(d889d570fa5445c1bf536ce92b6e266a) complete. Timing: real 0.123s	user 0.093s	sys 0.021s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":561,"lbm_read_time_us":8078,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21314,"lbm_writes_lt_1ms":443,"mutex_wait_us":22,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:34.156704 11812 maintenance_manager.cc:419] P ea041e63be0642dcbbaad383994a116d: Scheduling FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a): perf score=10.126437
I20260812 06:18:34.211365 11738 maintenance_manager.cc:643] P ea041e63be0642dcbbaad383994a116d: FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a) complete. Timing: real 0.054s	user 0.026s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17213,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:18:34.212076 11812 maintenance_manager.cc:419] P ea041e63be0642dcbbaad383994a116d: Scheduling FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a): perf score=2.188937
I20260812 06:18:34.227520 11738 maintenance_manager.cc:643] P ea041e63be0642dcbbaad383994a116d: FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a) complete. Timing: real 0.015s	user 0.007s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5683,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:34.228111 11812 maintenance_manager.cc:419] P ea041e63be0642dcbbaad383994a116d: Scheduling FlushMRSOp(d889d570fa5445c1bf536ce92b6e266a): perf score=1.000000
I20260812 06:18:34.278216 11738 maintenance_manager.cc:643] P ea041e63be0642dcbbaad383994a116d: FlushMRSOp(d889d570fa5445c1bf536ce92b6e266a) complete. Timing: real 0.050s	user 0.032s	sys 0.001s Metrics: {"bytes_written":1275443,"cfile_init":1,"dirs.queue_time_us":77,"dirs.run_cpu_time_us":270,"dirs.run_wall_time_us":1330,"drs_written":1,"lbm_read_time_us":48,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1983,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:18:34.279135 11812 maintenance_manager.cc:419] P ea041e63be0642dcbbaad383994a116d: Scheduling LogGCOp(d889d570fa5445c1bf536ce92b6e266a): free 121006437 bytes of WAL
I20260812 06:18:34.279400 11738 log_reader.cc:385] T d889d570fa5445c1bf536ce92b6e266a: removed 12 log segments from log reader
I20260812 06:18:34.279464 11738 log.cc:1079] T d889d570fa5445c1bf536ce92b6e266a P ea041e63be0642dcbbaad383994a116d: Deleting log segment in path: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515512185349-11613-0/minicluster-data/ts-0-root/wals/d889d570fa5445c1bf536ce92b6e266a/wal-000000003 (ops 12-16)
I20260812 06:18:34.279498 11738 log.cc:1079] T d889d570fa5445c1bf536ce92b6e266a P ea041e63be0642dcbbaad383994a116d: Deleting log segment in path: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515512185349-11613-0/minicluster-data/ts-0-root/wals/d889d570fa5445c1bf536ce92b6e266a/wal-000000004 (ops 17-21)
I20260812 06:18:34.279526 11738 log.cc:1079] T d889d570fa5445c1bf536ce92b6e266a P ea041e63be0642dcbbaad383994a116d: Deleting log segment in path: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515512185349-11613-0/minicluster-data/ts-0-root/wals/d889d570fa5445c1bf536ce92b6e266a/wal-000000005 (ops 22-26)
I20260812 06:18:34.279600 11738 log.cc:1079] T d889d570fa5445c1bf536ce92b6e266a P ea041e63be0642dcbbaad383994a116d: Deleting log segment in path: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515512185349-11613-0/minicluster-data/ts-0-root/wals/d889d570fa5445c1bf536ce92b6e266a/wal-000000006 (ops 27-31)
I20260812 06:18:34.279632 11738 log.cc:1079] T d889d570fa5445c1bf536ce92b6e266a P ea041e63be0642dcbbaad383994a116d: Deleting log segment in path: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515512185349-11613-0/minicluster-data/ts-0-root/wals/d889d570fa5445c1bf536ce92b6e266a/wal-000000007 (ops 32-36)
I20260812 06:18:34.279682 11738 log.cc:1079] T d889d570fa5445c1bf536ce92b6e266a P ea041e63be0642dcbbaad383994a116d: Deleting log segment in path: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515512185349-11613-0/minicluster-data/ts-0-root/wals/d889d570fa5445c1bf536ce92b6e266a/wal-000000008 (ops 37-41)
I20260812 06:18:34.279716 11738 log.cc:1079] T d889d570fa5445c1bf536ce92b6e266a P ea041e63be0642dcbbaad383994a116d: Deleting log segment in path: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515512185349-11613-0/minicluster-data/ts-0-root/wals/d889d570fa5445c1bf536ce92b6e266a/wal-000000009 (ops 42-46)
I20260812 06:18:34.279738 11738 log.cc:1079] T d889d570fa5445c1bf536ce92b6e266a P ea041e63be0642dcbbaad383994a116d: Deleting log segment in path: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515512185349-11613-0/minicluster-data/ts-0-root/wals/d889d570fa5445c1bf536ce92b6e266a/wal-000000010 (ops 47-50)
I20260812 06:18:34.279789 11738 log.cc:1079] T d889d570fa5445c1bf536ce92b6e266a P ea041e63be0642dcbbaad383994a116d: Deleting log segment in path: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515512185349-11613-0/minicluster-data/ts-0-root/wals/d889d570fa5445c1bf536ce92b6e266a/wal-000000011 (ops 51-55)
I20260812 06:18:34.279819 11738 log.cc:1079] T d889d570fa5445c1bf536ce92b6e266a P ea041e63be0642dcbbaad383994a116d: Deleting log segment in path: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515512185349-11613-0/minicluster-data/ts-0-root/wals/d889d570fa5445c1bf536ce92b6e266a/wal-000000012 (ops 56-60)
I20260812 06:18:34.279876 11738 log.cc:1079] T d889d570fa5445c1bf536ce92b6e266a P ea041e63be0642dcbbaad383994a116d: Deleting log segment in path: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515512185349-11613-0/minicluster-data/ts-0-root/wals/d889d570fa5445c1bf536ce92b6e266a/wal-000000013 (ops 61-65)
I20260812 06:18:34.279907 11738 log.cc:1079] T d889d570fa5445c1bf536ce92b6e266a P ea041e63be0642dcbbaad383994a116d: Deleting log segment in path: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515512185349-11613-0/minicluster-data/ts-0-root/wals/d889d570fa5445c1bf536ce92b6e266a/wal-000000014 (ops 66-70)
I20260812 06:18:34.304335 11738 maintenance_manager.cc:643] P ea041e63be0642dcbbaad383994a116d: LogGCOp(d889d570fa5445c1bf536ce92b6e266a) complete. Timing: real 0.025s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:18:34.304818 11812 maintenance_manager.cc:419] P ea041e63be0642dcbbaad383994a116d: Scheduling FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a): perf score=3.181125
I20260812 06:18:34.327800 11738 maintenance_manager.cc:643] P ea041e63be0642dcbbaad383994a116d: FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a) complete. Timing: real 0.023s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":5392,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:34.328353 11812 maintenance_manager.cc:419] P ea041e63be0642dcbbaad383994a116d: Scheduling UndoDeltaBlockGCOp(d889d570fa5445c1bf536ce92b6e266a): 482 bytes on disk
I20260812 06:18:34.328784 11738 maintenance_manager.cc:643] P ea041e63be0642dcbbaad383994a116d: UndoDeltaBlockGCOp(d889d570fa5445c1bf536ce92b6e266a) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4}
I20260812 06:18:34.329363 11812 maintenance_manager.cc:419] P ea041e63be0642dcbbaad383994a116d: Scheduling FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a): perf score=2.188937
I20260812 06:18:34.341014 11738 maintenance_manager.cc:643] P ea041e63be0642dcbbaad383994a116d: FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4174,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:34.341552 11812 maintenance_manager.cc:419] P ea041e63be0642dcbbaad383994a116d: Scheduling MajorDeltaCompactionOp(d889d570fa5445c1bf536ce92b6e266a): perf score=1.000000
I20260812 06:18:34.556252 11738 maintenance_manager.cc:643] P ea041e63be0642dcbbaad383994a116d: MajorDeltaCompactionOp(d889d570fa5445c1bf536ce92b6e266a) complete. Timing: real 0.215s	user 0.141s	sys 0.061s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877329,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1755,"lbm_read_time_us":13419,"lbm_reads_lt_1ms":674,"lbm_write_time_us":34664,"lbm_writes_lt_1ms":643,"mutex_wait_us":1071,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":7424,"thread_start_us":93,"threads_started":1,"update_count":3000}
I20260812 06:18:34.556936 11812 maintenance_manager.cc:419] P ea041e63be0642dcbbaad383994a116d: Scheduling FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a): perf score=14.095187
I20260812 06:18:34.600277 11738 maintenance_manager.cc:643] P ea041e63be0642dcbbaad383994a116d: FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a) complete. Timing: real 0.043s	user 0.032s	sys 0.008s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":18585,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:34.600929 11812 maintenance_manager.cc:419] P ea041e63be0642dcbbaad383994a116d: Scheduling MajorDeltaCompactionOp(d889d570fa5445c1bf536ce92b6e266a): perf score=1.000000
I20260812 06:18:34.756361 11738 maintenance_manager.cc:643] P ea041e63be0642dcbbaad383994a116d: MajorDeltaCompactionOp(d889d570fa5445c1bf536ce92b6e266a) complete. Timing: real 0.155s	user 0.106s	sys 0.046s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672156,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":226,"lbm_read_time_us":10845,"lbm_reads_lt_1ms":467,"lbm_write_time_us":26948,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":442,"mutex_wait_us":66,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":13952,"update_count":2000}
I20260812 06:18:34.757051 11812 maintenance_manager.cc:419] P ea041e63be0642dcbbaad383994a116d: Scheduling FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a): perf score=10.126437
I20260812 06:18:34.798960 11738 maintenance_manager.cc:643] P ea041e63be0642dcbbaad383994a116d: FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a) complete. Timing: real 0.042s	user 0.018s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16698,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:34.799649 11812 maintenance_manager.cc:419] P ea041e63be0642dcbbaad383994a116d: Scheduling FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a): perf score=2.188937
I20260812 06:18:34.817464 11738 maintenance_manager.cc:643] P ea041e63be0642dcbbaad383994a116d: FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a) complete. Timing: real 0.016s	user 0.015s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6341,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:34.817894 11812 maintenance_manager.cc:419] P ea041e63be0642dcbbaad383994a116d: Scheduling MajorDeltaCompactionOp(d889d570fa5445c1bf536ce92b6e266a): perf score=1.000000
I20260812 06:18:34.956461 11738 maintenance_manager.cc:643] P ea041e63be0642dcbbaad383994a116d: MajorDeltaCompactionOp(d889d570fa5445c1bf536ce92b6e266a) complete. Timing: real 0.138s	user 0.105s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":522,"lbm_read_time_us":10010,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24558,"lbm_writes_lt_1ms":443,"mutex_wait_us":224,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:34.957010 11812 maintenance_manager.cc:419] P ea041e63be0642dcbbaad383994a116d: Scheduling FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a): perf score=10.126437
I20260812 06:18:34.996305 11738 maintenance_manager.cc:643] P ea041e63be0642dcbbaad383994a116d: FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a) complete. Timing: real 0.039s	user 0.021s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15080,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:34.996809 11812 maintenance_manager.cc:419] P ea041e63be0642dcbbaad383994a116d: Scheduling FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a): perf score=2.188937
I20260812 06:18:35.011871 11738 maintenance_manager.cc:643] P ea041e63be0642dcbbaad383994a116d: FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a) complete. Timing: real 0.015s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5680,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:35.012372 11812 maintenance_manager.cc:419] P ea041e63be0642dcbbaad383994a116d: Scheduling MajorDeltaCompactionOp(d889d570fa5445c1bf536ce92b6e266a): perf score=1.000000
I20260812 06:18:35.147537 11738 maintenance_manager.cc:643] P ea041e63be0642dcbbaad383994a116d: MajorDeltaCompactionOp(d889d570fa5445c1bf536ce92b6e266a) complete. Timing: real 0.135s	user 0.116s	sys 0.019s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":640,"lbm_read_time_us":10312,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22731,"lbm_writes_lt_1ms":443,"mutex_wait_us":241,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:35.148046 11812 maintenance_manager.cc:419] P ea041e63be0642dcbbaad383994a116d: Scheduling FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a): perf score=10.126437
I20260812 06:18:35.187659 11738 maintenance_manager.cc:643] P ea041e63be0642dcbbaad383994a116d: FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a) complete. Timing: real 0.039s	user 0.008s	sys 0.021s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":12981,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:35.188293 11812 maintenance_manager.cc:419] P ea041e63be0642dcbbaad383994a116d: Scheduling FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a): perf score=2.188937
I20260812 06:18:35.203778 11738 maintenance_manager.cc:643] P ea041e63be0642dcbbaad383994a116d: FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a) complete. Timing: real 0.015s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5637,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:35.204407 11812 maintenance_manager.cc:419] P ea041e63be0642dcbbaad383994a116d: Scheduling MajorDeltaCompactionOp(d889d570fa5445c1bf536ce92b6e266a): perf score=1.000000
I20260812 06:18:35.345031 11738 maintenance_manager.cc:643] P ea041e63be0642dcbbaad383994a116d: MajorDeltaCompactionOp(d889d570fa5445c1bf536ce92b6e266a) complete. Timing: real 0.140s	user 0.104s	sys 0.033s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":182,"lbm_read_time_us":8902,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25929,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1536,"update_count":2000}
I20260812 06:18:35.345703 11812 maintenance_manager.cc:419] P ea041e63be0642dcbbaad383994a116d: Scheduling FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a): perf score=10.126437
I20260812 06:18:35.393884 11738 maintenance_manager.cc:643] P ea041e63be0642dcbbaad383994a116d: FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a) complete. Timing: real 0.048s	user 0.017s	sys 0.027s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13876,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:35.394474 11812 maintenance_manager.cc:419] P ea041e63be0642dcbbaad383994a116d: Scheduling FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a): perf score=2.188937
I20260812 06:18:35.409935 11738 maintenance_manager.cc:643] P ea041e63be0642dcbbaad383994a116d: FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a) complete. Timing: real 0.015s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5724,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:35.410538 11812 maintenance_manager.cc:419] P ea041e63be0642dcbbaad383994a116d: Scheduling MajorDeltaCompactionOp(d889d570fa5445c1bf536ce92b6e266a): perf score=1.000000
I20260812 06:18:35.568439 11738 maintenance_manager.cc:643] P ea041e63be0642dcbbaad383994a116d: MajorDeltaCompactionOp(d889d570fa5445c1bf536ce92b6e266a) complete. Timing: real 0.158s	user 0.106s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1085,"lbm_read_time_us":11691,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21835,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:35.569069 11812 maintenance_manager.cc:419] P ea041e63be0642dcbbaad383994a116d: Scheduling FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a): perf score=10.126437
I20260812 06:18:35.606917 11738 maintenance_manager.cc:643] P ea041e63be0642dcbbaad383994a116d: FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a) complete. Timing: real 0.038s	user 0.019s	sys 0.013s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":15039,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:35.607399 11812 maintenance_manager.cc:419] P ea041e63be0642dcbbaad383994a116d: Scheduling MajorDeltaCompactionOp(d889d570fa5445c1bf536ce92b6e266a): perf score=1.000000
I20260812 06:18:35.720029 11738 maintenance_manager.cc:643] P ea041e63be0642dcbbaad383994a116d: MajorDeltaCompactionOp(d889d570fa5445c1bf536ce92b6e266a) complete. Timing: real 0.112s	user 0.082s	sys 0.024s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16569748,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":1390,"lbm_read_time_us":5835,"lbm_reads_lt_1ms":363,"lbm_write_time_us":18749,"lbm_writes_lt_1ms":343,"mutex_wait_us":491,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":5888,"update_count":1500}
I20260812 06:18:35.720652 11812 maintenance_manager.cc:419] P ea041e63be0642dcbbaad383994a116d: Scheduling FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a): perf score=10.126437
I20260812 06:18:35.759783 11738 maintenance_manager.cc:643] P ea041e63be0642dcbbaad383994a116d: FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a) complete. Timing: real 0.039s	user 0.019s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16581,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:35.760425 11812 maintenance_manager.cc:419] P ea041e63be0642dcbbaad383994a116d: Scheduling FlushMRSOp(d889d570fa5445c1bf536ce92b6e266a): perf score=1.000000
I20260812 06:18:35.792058 11738 maintenance_manager.cc:643] P ea041e63be0642dcbbaad383994a116d: FlushMRSOp(d889d570fa5445c1bf536ce92b6e266a) complete. Timing: real 0.031s	user 0.030s	sys 0.000s Metrics: {"bytes_written":1152514,"cfile_init":1,"dirs.queue_time_us":72,"dirs.run_cpu_time_us":176,"dirs.run_wall_time_us":1420,"drs_written":1,"lbm_read_time_us":43,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1434,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:35.792761 11812 maintenance_manager.cc:419] P ea041e63be0642dcbbaad383994a116d: Scheduling LogGCOp(d889d570fa5445c1bf536ce92b6e266a): free 115943175 bytes of WAL
I20260812 06:18:35.792973 11738 log_reader.cc:385] T d889d570fa5445c1bf536ce92b6e266a: removed 11 log segments from log reader
I20260812 06:18:35.793016 11738 log.cc:1079] T d889d570fa5445c1bf536ce92b6e266a P ea041e63be0642dcbbaad383994a116d: Deleting log segment in path: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515512185349-11613-0/minicluster-data/ts-0-root/wals/d889d570fa5445c1bf536ce92b6e266a/wal-000000015 (ops 71-75)
I20260812 06:18:35.793056 11738 log.cc:1079] T d889d570fa5445c1bf536ce92b6e266a P ea041e63be0642dcbbaad383994a116d: Deleting log segment in path: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515512185349-11613-0/minicluster-data/ts-0-root/wals/d889d570fa5445c1bf536ce92b6e266a/wal-000000016 (ops 76-80)
I20260812 06:18:35.793088 11738 log.cc:1079] T d889d570fa5445c1bf536ce92b6e266a P ea041e63be0642dcbbaad383994a116d: Deleting log segment in path: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515512185349-11613-0/minicluster-data/ts-0-root/wals/d889d570fa5445c1bf536ce92b6e266a/wal-000000017 (ops 81-85)
I20260812 06:18:35.793118 11738 log.cc:1079] T d889d570fa5445c1bf536ce92b6e266a P ea041e63be0642dcbbaad383994a116d: Deleting log segment in path: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515512185349-11613-0/minicluster-data/ts-0-root/wals/d889d570fa5445c1bf536ce92b6e266a/wal-000000018 (ops 86-90)
I20260812 06:18:35.793146 11738 log.cc:1079] T d889d570fa5445c1bf536ce92b6e266a P ea041e63be0642dcbbaad383994a116d: Deleting log segment in path: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515512185349-11613-0/minicluster-data/ts-0-root/wals/d889d570fa5445c1bf536ce92b6e266a/wal-000000019 (ops 91-95)
I20260812 06:18:35.793203 11738 log.cc:1079] T d889d570fa5445c1bf536ce92b6e266a P ea041e63be0642dcbbaad383994a116d: Deleting log segment in path: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515512185349-11613-0/minicluster-data/ts-0-root/wals/d889d570fa5445c1bf536ce92b6e266a/wal-000000020 (ops 96-100)
I20260812 06:18:35.793239 11738 log.cc:1079] T d889d570fa5445c1bf536ce92b6e266a P ea041e63be0642dcbbaad383994a116d: Deleting log segment in path: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515512185349-11613-0/minicluster-data/ts-0-root/wals/d889d570fa5445c1bf536ce92b6e266a/wal-000000021 (ops 101-105)
I20260812 06:18:35.793273 11738 log.cc:1079] T d889d570fa5445c1bf536ce92b6e266a P ea041e63be0642dcbbaad383994a116d: Deleting log segment in path: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515512185349-11613-0/minicluster-data/ts-0-root/wals/d889d570fa5445c1bf536ce92b6e266a/wal-000000022 (ops 106-110)
I20260812 06:18:35.793306 11738 log.cc:1079] T d889d570fa5445c1bf536ce92b6e266a P ea041e63be0642dcbbaad383994a116d: Deleting log segment in path: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515512185349-11613-0/minicluster-data/ts-0-root/wals/d889d570fa5445c1bf536ce92b6e266a/wal-000000023 (ops 111-115)
I20260812 06:18:35.793336 11738 log.cc:1079] T d889d570fa5445c1bf536ce92b6e266a P ea041e63be0642dcbbaad383994a116d: Deleting log segment in path: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515512185349-11613-0/minicluster-data/ts-0-root/wals/d889d570fa5445c1bf536ce92b6e266a/wal-000000024 (ops 116-120)
I20260812 06:18:35.793368 11738 log.cc:1079] T d889d570fa5445c1bf536ce92b6e266a P ea041e63be0642dcbbaad383994a116d: Deleting log segment in path: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515512185349-11613-0/minicluster-data/ts-0-root/wals/d889d570fa5445c1bf536ce92b6e266a/wal-000000025 (ops 121-125)
I20260812 06:18:35.814728 11738 maintenance_manager.cc:643] P ea041e63be0642dcbbaad383994a116d: LogGCOp(d889d570fa5445c1bf536ce92b6e266a) complete. Timing: real 0.022s	user 0.001s	sys 0.019s Metrics: {}
I20260812 06:18:35.815151 11812 maintenance_manager.cc:419] P ea041e63be0642dcbbaad383994a116d: Scheduling UndoDeltaBlockGCOp(d889d570fa5445c1bf536ce92b6e266a): 448 bytes on disk
I20260812 06:18:35.815568 11738 maintenance_manager.cc:643] P ea041e63be0642dcbbaad383994a116d: UndoDeltaBlockGCOp(d889d570fa5445c1bf536ce92b6e266a) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4}
I20260812 06:18:35.816079 11812 maintenance_manager.cc:419] P ea041e63be0642dcbbaad383994a116d: Scheduling FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a): perf score=3.181125
I20260812 06:18:35.829977 11738 maintenance_manager.cc:643] P ea041e63be0642dcbbaad383994a116d: FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a) complete. Timing: real 0.014s	user 0.004s	sys 0.007s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4107,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:35.830495 11812 maintenance_manager.cc:419] P ea041e63be0642dcbbaad383994a116d: Scheduling LogGCOp(d889d570fa5445c1bf536ce92b6e266a): free 12017940 bytes of WAL
I20260812 06:18:35.830698 11738 log_reader.cc:385] T d889d570fa5445c1bf536ce92b6e266a: removed 1 log segments from log reader
I20260812 06:18:35.830745 11738 log.cc:1079] T d889d570fa5445c1bf536ce92b6e266a P ea041e63be0642dcbbaad383994a116d: Deleting log segment in path: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515512185349-11613-0/minicluster-data/ts-0-root/wals/d889d570fa5445c1bf536ce92b6e266a/wal-000000026 (ops 126-130)
I20260812 06:18:35.833324 11738 maintenance_manager.cc:643] P ea041e63be0642dcbbaad383994a116d: LogGCOp(d889d570fa5445c1bf536ce92b6e266a) complete. Timing: real 0.003s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:18:35.833637 11812 maintenance_manager.cc:419] P ea041e63be0642dcbbaad383994a116d: Scheduling FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a): perf score=2.188937
I20260812 06:18:35.847872 11738 maintenance_manager.cc:643] P ea041e63be0642dcbbaad383994a116d: FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a) complete. Timing: real 0.014s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5141,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:35.848421 11812 maintenance_manager.cc:419] P ea041e63be0642dcbbaad383994a116d: Scheduling MajorDeltaCompactionOp(d889d570fa5445c1bf536ce92b6e266a): perf score=1.000000
I20260812 06:18:36.029641 11738 maintenance_manager.cc:643] P ea041e63be0642dcbbaad383994a116d: MajorDeltaCompactionOp(d889d570fa5445c1bf536ce92b6e266a) complete. Timing: real 0.181s	user 0.122s	sys 0.051s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774798,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1887,"lbm_read_time_us":12015,"lbm_reads_lt_1ms":573,"lbm_write_time_us":35073,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":542,"peak_mem_usage":63115900,"reinsert_count":0,"thread_start_us":97,"threads_started":1,"update_count":2500}
I20260812 06:18:36.030172 11812 maintenance_manager.cc:419] P ea041e63be0642dcbbaad383994a116d: Scheduling FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a): perf score=11.118625
I20260812 06:18:36.072365 11738 maintenance_manager.cc:643] P ea041e63be0642dcbbaad383994a116d: FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a) complete. Timing: real 0.040s	user 0.033s	sys 0.004s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":16859,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:36.072939 11812 maintenance_manager.cc:419] P ea041e63be0642dcbbaad383994a116d: Scheduling FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a): perf score=2.188937
I20260812 06:18:36.085057 11738 maintenance_manager.cc:643] P ea041e63be0642dcbbaad383994a116d: FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a) complete. Timing: real 0.012s	user 0.002s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4459,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:36.085601 11812 maintenance_manager.cc:419] P ea041e63be0642dcbbaad383994a116d: Scheduling MajorDeltaCompactionOp(d889d570fa5445c1bf536ce92b6e266a): perf score=1.000000
I20260812 06:18:36.243182 11738 maintenance_manager.cc:643] P ea041e63be0642dcbbaad383994a116d: MajorDeltaCompactionOp(d889d570fa5445c1bf536ce92b6e266a) complete. Timing: real 0.157s	user 0.117s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672269,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":880,"lbm_read_time_us":10551,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25500,"lbm_writes_lt_1ms":443,"mutex_wait_us":293,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3328,"update_count":2000}
I20260812 06:18:36.243685 11812 maintenance_manager.cc:419] P ea041e63be0642dcbbaad383994a116d: Scheduling FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a): perf score=10.126437
I20260812 06:18:36.281232 11738 maintenance_manager.cc:643] P ea041e63be0642dcbbaad383994a116d: FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a) complete. Timing: real 0.037s	user 0.026s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16070,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:36.281673 11812 maintenance_manager.cc:419] P ea041e63be0642dcbbaad383994a116d: Scheduling FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a): perf score=2.188937
I20260812 06:18:36.293929 11738 maintenance_manager.cc:643] P ea041e63be0642dcbbaad383994a116d: FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a) complete. Timing: real 0.012s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4210,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:36.294442 11812 maintenance_manager.cc:419] P ea041e63be0642dcbbaad383994a116d: Scheduling MajorDeltaCompactionOp(d889d570fa5445c1bf536ce92b6e266a): perf score=1.000000
I20260812 06:18:36.421702 11738 maintenance_manager.cc:643] P ea041e63be0642dcbbaad383994a116d: MajorDeltaCompactionOp(d889d570fa5445c1bf536ce92b6e266a) complete. Timing: real 0.127s	user 0.099s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":158,"lbm_read_time_us":7636,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22660,"lbm_writes_lt_1ms":443,"mutex_wait_us":18,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11392,"update_count":2000}
I20260812 06:18:36.422775 11812 maintenance_manager.cc:419] P ea041e63be0642dcbbaad383994a116d: Scheduling FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a): perf score=10.126437
I20260812 06:18:36.461894 11738 maintenance_manager.cc:643] P ea041e63be0642dcbbaad383994a116d: FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a) complete. Timing: real 0.039s	user 0.024s	sys 0.008s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":13462,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:36.462493 11812 maintenance_manager.cc:419] P ea041e63be0642dcbbaad383994a116d: Scheduling FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a): perf score=2.188937
I20260812 06:18:36.478137 11738 maintenance_manager.cc:643] P ea041e63be0642dcbbaad383994a116d: FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a) complete. Timing: real 0.015s	user 0.005s	sys 0.010s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5768,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:36.478823 11812 maintenance_manager.cc:419] P ea041e63be0642dcbbaad383994a116d: Scheduling MajorDeltaCompactionOp(d889d570fa5445c1bf536ce92b6e266a): perf score=1.000000
I20260812 06:18:36.606298 11738 maintenance_manager.cc:643] P ea041e63be0642dcbbaad383994a116d: MajorDeltaCompactionOp(d889d570fa5445c1bf536ce92b6e266a) complete. Timing: real 0.127s	user 0.118s	sys 0.009s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":281,"lbm_read_time_us":7655,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24653,"lbm_writes_lt_1ms":443,"mutex_wait_us":100,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:18:36.606891 11812 maintenance_manager.cc:419] P ea041e63be0642dcbbaad383994a116d: Scheduling FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a): perf score=10.126437
I20260812 06:18:36.648164 11738 maintenance_manager.cc:643] P ea041e63be0642dcbbaad383994a116d: FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a) complete. Timing: real 0.041s	user 0.028s	sys 0.007s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":16517,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:36.649044 11812 maintenance_manager.cc:419] P ea041e63be0642dcbbaad383994a116d: Scheduling MajorDeltaCompactionOp(d889d570fa5445c1bf536ce92b6e266a): perf score=1.000000
I20260812 06:18:36.758803 11738 maintenance_manager.cc:643] P ea041e63be0642dcbbaad383994a116d: MajorDeltaCompactionOp(d889d570fa5445c1bf536ce92b6e266a) complete. Timing: real 0.110s	user 0.090s	sys 0.019s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16569748,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":638,"lbm_read_time_us":7574,"lbm_reads_lt_1ms":363,"lbm_write_time_us":21010,"lbm_writes_lt_1ms":343,"mutex_wait_us":55,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":1920,"update_count":1500}
I20260812 06:18:36.759316 11812 maintenance_manager.cc:419] P ea041e63be0642dcbbaad383994a116d: Scheduling FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a): perf score=10.126437
I20260812 06:18:36.818987 11738 maintenance_manager.cc:643] P ea041e63be0642dcbbaad383994a116d: FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a) complete. Timing: real 0.060s	user 0.018s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":39408,"lbm_writes_10-100_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:18:36.819535 11812 maintenance_manager.cc:419] P ea041e63be0642dcbbaad383994a116d: Scheduling FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a): perf score=2.188937
I20260812 06:18:36.833140 11738 maintenance_manager.cc:643] P ea041e63be0642dcbbaad383994a116d: FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a) complete. Timing: real 0.013s	user 0.000s	sys 0.011s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4855,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:36.833652 11812 maintenance_manager.cc:419] P ea041e63be0642dcbbaad383994a116d: Scheduling MajorDeltaCompactionOp(d889d570fa5445c1bf536ce92b6e266a): perf score=1.000000
I20260812 06:18:36.962651 11738 maintenance_manager.cc:643] P ea041e63be0642dcbbaad383994a116d: MajorDeltaCompactionOp(d889d570fa5445c1bf536ce92b6e266a) complete. Timing: real 0.129s	user 0.105s	sys 0.022s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":589,"lbm_read_time_us":7361,"lbm_reads_lt_1ms":468,"lbm_write_time_us":22847,"lbm_writes_lt_1ms":443,"mutex_wait_us":41,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:18:36.963363 11812 maintenance_manager.cc:419] P ea041e63be0642dcbbaad383994a116d: Scheduling FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a): perf score=10.126437
I20260812 06:18:37.003224 11738 maintenance_manager.cc:643] P ea041e63be0642dcbbaad383994a116d: FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a) complete. Timing: real 0.040s	user 0.028s	sys 0.008s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":16417,"lbm_writes_lt_1ms":313,"mutex_wait_us":1424,"reinsert_count":0,"update_count":1550}
I20260812 06:18:37.003695 11812 maintenance_manager.cc:419] P ea041e63be0642dcbbaad383994a116d: Scheduling FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a): perf score=2.188937
I20260812 06:18:37.016448 11738 maintenance_manager.cc:643] P ea041e63be0642dcbbaad383994a116d: FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a) complete. Timing: real 0.013s	user 0.010s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4525,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:37.017061 11812 maintenance_manager.cc:419] P ea041e63be0642dcbbaad383994a116d: Scheduling MajorDeltaCompactionOp(d889d570fa5445c1bf536ce92b6e266a): perf score=1.000000
I20260812 06:18:37.139106 11738 maintenance_manager.cc:643] P ea041e63be0642dcbbaad383994a116d: MajorDeltaCompactionOp(d889d570fa5445c1bf536ce92b6e266a) complete. Timing: real 0.122s	user 0.091s	sys 0.030s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":743,"lbm_read_time_us":7499,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24160,"lbm_writes_lt_1ms":443,"mutex_wait_us":105,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:18:37.139727 11812 maintenance_manager.cc:419] P ea041e63be0642dcbbaad383994a116d: Scheduling FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a): perf score=10.126437
I20260812 06:18:37.171054 11738 maintenance_manager.cc:643] P ea041e63be0642dcbbaad383994a116d: FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a) complete. Timing: real 0.030s	user 0.021s	sys 0.007s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13147,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:37.171628 11812 maintenance_manager.cc:419] P ea041e63be0642dcbbaad383994a116d: Scheduling FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a): perf score=2.188937
I20260812 06:18:37.186070 11738 maintenance_manager.cc:643] P ea041e63be0642dcbbaad383994a116d: FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a) complete. Timing: real 0.014s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6047,"lbm_writes_lt_1ms":103,"reinsert_count":0,"spinlock_wait_cycles":14080,"update_count":500}
I20260812 06:18:37.186545 11812 maintenance_manager.cc:419] P ea041e63be0642dcbbaad383994a116d: Scheduling FlushMRSOp(d889d570fa5445c1bf536ce92b6e266a): perf score=1.000000
I20260812 06:18:37.217461 11738 maintenance_manager.cc:643] P ea041e63be0642dcbbaad383994a116d: FlushMRSOp(d889d570fa5445c1bf536ce92b6e266a) complete. Timing: real 0.031s	user 0.026s	sys 0.004s Metrics: {"bytes_written":1234477,"cfile_init":1,"dirs.queue_time_us":58,"dirs.run_cpu_time_us":216,"dirs.run_wall_time_us":1298,"drs_written":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1371,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:18:37.218236 11812 maintenance_manager.cc:419] P ea041e63be0642dcbbaad383994a116d: Scheduling LogGCOp(d889d570fa5445c1bf536ce92b6e266a): free 112239554 bytes of WAL
I20260812 06:18:37.218509 11738 log_reader.cc:385] T d889d570fa5445c1bf536ce92b6e266a: removed 11 log segments from log reader
I20260812 06:18:37.218566 11738 log.cc:1079] T d889d570fa5445c1bf536ce92b6e266a P ea041e63be0642dcbbaad383994a116d: Deleting log segment in path: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515512185349-11613-0/minicluster-data/ts-0-root/wals/d889d570fa5445c1bf536ce92b6e266a/wal-000000027 (ops 131-135)
I20260812 06:18:37.218607 11738 log.cc:1079] T d889d570fa5445c1bf536ce92b6e266a P ea041e63be0642dcbbaad383994a116d: Deleting log segment in path: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515512185349-11613-0/minicluster-data/ts-0-root/wals/d889d570fa5445c1bf536ce92b6e266a/wal-000000028 (ops 136-140)
I20260812 06:18:37.218638 11738 log.cc:1079] T d889d570fa5445c1bf536ce92b6e266a P ea041e63be0642dcbbaad383994a116d: Deleting log segment in path: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515512185349-11613-0/minicluster-data/ts-0-root/wals/d889d570fa5445c1bf536ce92b6e266a/wal-000000029 (ops 141-144)
I20260812 06:18:37.218672 11738 log.cc:1079] T d889d570fa5445c1bf536ce92b6e266a P ea041e63be0642dcbbaad383994a116d: Deleting log segment in path: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515512185349-11613-0/minicluster-data/ts-0-root/wals/d889d570fa5445c1bf536ce92b6e266a/wal-000000030 (ops 145-149)
I20260812 06:18:37.218703 11738 log.cc:1079] T d889d570fa5445c1bf536ce92b6e266a P ea041e63be0642dcbbaad383994a116d: Deleting log segment in path: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515512185349-11613-0/minicluster-data/ts-0-root/wals/d889d570fa5445c1bf536ce92b6e266a/wal-000000031 (ops 150-154)
I20260812 06:18:37.218773 11738 log.cc:1079] T d889d570fa5445c1bf536ce92b6e266a P ea041e63be0642dcbbaad383994a116d: Deleting log segment in path: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515512185349-11613-0/minicluster-data/ts-0-root/wals/d889d570fa5445c1bf536ce92b6e266a/wal-000000032 (ops 155-159)
I20260812 06:18:37.218804 11738 log.cc:1079] T d889d570fa5445c1bf536ce92b6e266a P ea041e63be0642dcbbaad383994a116d: Deleting log segment in path: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515512185349-11613-0/minicluster-data/ts-0-root/wals/d889d570fa5445c1bf536ce92b6e266a/wal-000000033 (ops 160-164)
I20260812 06:18:37.218828 11738 log.cc:1079] T d889d570fa5445c1bf536ce92b6e266a P ea041e63be0642dcbbaad383994a116d: Deleting log segment in path: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515512185349-11613-0/minicluster-data/ts-0-root/wals/d889d570fa5445c1bf536ce92b6e266a/wal-000000034 (ops 165-169)
I20260812 06:18:37.218858 11738 log.cc:1079] T d889d570fa5445c1bf536ce92b6e266a P ea041e63be0642dcbbaad383994a116d: Deleting log segment in path: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515512185349-11613-0/minicluster-data/ts-0-root/wals/d889d570fa5445c1bf536ce92b6e266a/wal-000000035 (ops 170-174)
I20260812 06:18:37.218897 11738 log.cc:1079] T d889d570fa5445c1bf536ce92b6e266a P ea041e63be0642dcbbaad383994a116d: Deleting log segment in path: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515512185349-11613-0/minicluster-data/ts-0-root/wals/d889d570fa5445c1bf536ce92b6e266a/wal-000000036 (ops 175-179)
I20260812 06:18:37.218927 11738 log.cc:1079] T d889d570fa5445c1bf536ce92b6e266a P ea041e63be0642dcbbaad383994a116d: Deleting log segment in path: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515512185349-11613-0/minicluster-data/ts-0-root/wals/d889d570fa5445c1bf536ce92b6e266a/wal-000000037 (ops 180-184)
I20260812 06:18:37.239686 11738 maintenance_manager.cc:643] P ea041e63be0642dcbbaad383994a116d: LogGCOp(d889d570fa5445c1bf536ce92b6e266a) complete. Timing: real 0.021s	user 0.000s	sys 0.019s Metrics: {}
I20260812 06:18:37.240154 11812 maintenance_manager.cc:419] P ea041e63be0642dcbbaad383994a116d: Scheduling FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a): perf score=4.173312
I20260812 06:18:37.255790 11738 maintenance_manager.cc:643] P ea041e63be0642dcbbaad383994a116d: FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a) complete. Timing: real 0.015s	user 0.010s	sys 0.003s Metrics: {"bytes_written":5374417,"delete_count":0,"lbm_write_time_us":6149,"lbm_writes_lt_1ms":134,"reinsert_count":0,"update_count":655}
I20260812 06:18:37.256323 11812 maintenance_manager.cc:419] P ea041e63be0642dcbbaad383994a116d: Scheduling LogGCOp(d889d570fa5445c1bf536ce92b6e266a): free 8767086 bytes of WAL
I20260812 06:18:37.256522 11738 log_reader.cc:385] T d889d570fa5445c1bf536ce92b6e266a: removed 1 log segments from log reader
I20260812 06:18:37.256567 11738 log.cc:1079] T d889d570fa5445c1bf536ce92b6e266a P ea041e63be0642dcbbaad383994a116d: Deleting log segment in path: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515512185349-11613-0/minicluster-data/ts-0-root/wals/d889d570fa5445c1bf536ce92b6e266a/wal-000000038 (ops 185-189)
I20260812 06:18:37.258023 11738 maintenance_manager.cc:643] P ea041e63be0642dcbbaad383994a116d: LogGCOp(d889d570fa5445c1bf536ce92b6e266a) complete. Timing: real 0.002s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:18:37.258356 11812 maintenance_manager.cc:419] P ea041e63be0642dcbbaad383994a116d: Scheduling UndoDeltaBlockGCOp(d889d570fa5445c1bf536ce92b6e266a): 472 bytes on disk
I20260812 06:18:37.258812 11738 maintenance_manager.cc:643] P ea041e63be0642dcbbaad383994a116d: UndoDeltaBlockGCOp(d889d570fa5445c1bf536ce92b6e266a) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4}
I20260812 06:18:37.259406 11812 maintenance_manager.cc:419] P ea041e63be0642dcbbaad383994a116d: Scheduling FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a): perf score=1.196750
I20260812 06:18:37.270062 11738 maintenance_manager.cc:643] P ea041e63be0642dcbbaad383994a116d: FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a) complete. Timing: real 0.010s	user 0.003s	sys 0.006s Metrics: {"bytes_written":2830880,"delete_count":0,"lbm_write_time_us":3678,"lbm_writes_lt_1ms":72,"reinsert_count":0,"update_count":345}
I20260812 06:18:37.270709 11812 maintenance_manager.cc:419] P ea041e63be0642dcbbaad383994a116d: Scheduling MajorDeltaCompactionOp(d889d570fa5445c1bf536ce92b6e266a): perf score=1.000000
I20260812 06:18:37.436208 11738 maintenance_manager.cc:643] P ea041e63be0642dcbbaad383994a116d: MajorDeltaCompactionOp(d889d570fa5445c1bf536ce92b6e266a) complete. Timing: real 0.165s	user 0.119s	sys 0.046s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877311,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":918,"lbm_read_time_us":12184,"lbm_reads_lt_1ms":666,"lbm_write_time_us":31474,"lbm_writes_lt_1ms":643,"mutex_wait_us":38,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":12160,"thread_start_us":76,"threads_started":1,"update_count":3000}
I20260812 06:18:37.436676 11812 maintenance_manager.cc:419] P ea041e63be0642dcbbaad383994a116d: Scheduling FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a): perf score=14.095187
I20260812 06:18:37.481287 11738 maintenance_manager.cc:643] P ea041e63be0642dcbbaad383994a116d: FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a) complete. Timing: real 0.044s	user 0.031s	sys 0.008s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":16826,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:37.481921 11812 maintenance_manager.cc:419] P ea041e63be0642dcbbaad383994a116d: Scheduling FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a): perf score=2.188937
I20260812 06:18:37.498852 11738 maintenance_manager.cc:643] P ea041e63be0642dcbbaad383994a116d: FlushDeltaMemStoresOp(d889d570fa5445c1bf536ce92b6e266a) complete. Timing: real 0.017s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6357,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:37.499419 11812 maintenance_manager.cc:419] P ea041e63be0642dcbbaad383994a116d: Scheduling MajorDeltaCompactionOp(d889d570fa5445c1bf536ce92b6e266a): perf score=1.000000
I20260812 06:18:37.525282 11613 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.014s	user 1.814s	sys 0.100s
I20260812 06:18:37.581467 11613 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.055s	user 0.005s	sys 0.000s
I20260812 06:18:37.582280 11613 tablet_server.cc:179] TabletServer@127.11.87.65:0 shutting down...
I20260812 06:18:37.620074 11738 maintenance_manager.cc:643] P ea041e63be0642dcbbaad383994a116d: MajorDeltaCompactionOp(d889d570fa5445c1bf536ce92b6e266a) complete. Timing: real 0.120s	user 0.096s	sys 0.024s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":376,"lbm_read_time_us":9488,"lbm_reads_lt_1ms":568,"lbm_write_time_us":22529,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1536,"update_count":2500}
I20260812 06:18:37.620723 11613 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:37.621208 11613 tablet_replica.cc:333] T d889d570fa5445c1bf536ce92b6e266a P ea041e63be0642dcbbaad383994a116d: stopping tablet replica
I20260812 06:18:37.621455 11613 raft_consensus.cc:2243] T d889d570fa5445c1bf536ce92b6e266a P ea041e63be0642dcbbaad383994a116d [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:37.621681 11613 raft_consensus.cc:2272] T d889d570fa5445c1bf536ce92b6e266a P ea041e63be0642dcbbaad383994a116d [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:37.636354 11613 tablet_server.cc:196] TabletServer@127.11.87.65:0 shutdown complete.
I20260812 06:18:37.665580 11613 master.cc:562] Master@127.11.87.126:42045 shutting down...
I20260812 06:18:37.668960 11613 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 19f7c91b400e4b5093f7ceac4aaa2ea1 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:37.669142 11613 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 19f7c91b400e4b5093f7ceac4aaa2ea1 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:37.669241 11613 tablet_replica.cc:333] T 00000000000000000000000000000000 P 19f7c91b400e4b5093f7ceac4aaa2ea1: stopping tablet replica
I20260812 06:18:37.681497 11613 master.cc:584] Master@127.11.87.126:42045 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5557 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:18:37.753028 11613 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.11.87.126:36831
I20260812 06:18:37.753523 11613 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:37.755990 11853 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:18:37.755990 11850 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:18:37.756135 11851 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:18:37.756214 11613 server_base.cc:1061] running on GCE node
I20260812 06:18:37.756436 11613 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:37.756475 11613 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:18:37.756489 11613 hybrid_clock.cc:648] HybridClock initialized: now 1786515517756489 us; error 0 us; skew 500 ppm
I20260812 06:18:37.757319 11613 webserver.cc:533] Webserver started at http://127.11.87.126:40839/ using document root <none> and password file <none>
I20260812 06:18:37.757479 11613 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:37.757520 11613 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:37.757577 11613 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:37.757910 11613 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515512185349-11613-0/minicluster-data/master-0-root/instance:
uuid: "276df5aed9c245fdb34fffe959b871db"
format_stamp: "Formatted at 2026-08-12 06:18:37 on dist-test-slave-vq2q"
I20260812 06:18:37.759286 11613 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:18:37.760236 11858 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:18:37.760478 11613 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:37.760550 11613 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515512185349-11613-0/minicluster-data/master-0-root
uuid: "276df5aed9c245fdb34fffe959b871db"
format_stamp: "Formatted at 2026-08-12 06:18:37 on dist-test-slave-vq2q"
I20260812 06:18:37.760623 11613 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515512185349-11613-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515512185349-11613-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515512185349-11613-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:18:37.808486 11613 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:37.808943 11613 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:37.812860 11613 rpc_server.cc:307] RPC server started. Bound to: 127.11.87.126:36831
I20260812 06:18:37.819240 11918 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.11.87.126:36831 every 8 connection(s)
I20260812 06:18:37.819828 11919 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:18:37.821659 11919 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 276df5aed9c245fdb34fffe959b871db: Bootstrap starting.
I20260812 06:18:37.822438 11919 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 276df5aed9c245fdb34fffe959b871db: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:37.823532 11919 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 276df5aed9c245fdb34fffe959b871db: No bootstrap required, opened a new log
I20260812 06:18:37.823971 11919 raft_consensus.cc:359] T 00000000000000000000000000000000 P 276df5aed9c245fdb34fffe959b871db [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "276df5aed9c245fdb34fffe959b871db" member_type: VOTER }
I20260812 06:18:37.824074 11919 raft_consensus.cc:385] T 00000000000000000000000000000000 P 276df5aed9c245fdb34fffe959b871db [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:37.824119 11919 raft_consensus.cc:740] T 00000000000000000000000000000000 P 276df5aed9c245fdb34fffe959b871db [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 276df5aed9c245fdb34fffe959b871db, State: Initialized, Role: FOLLOWER
I20260812 06:18:37.824268 11919 consensus_queue.cc:260] T 00000000000000000000000000000000 P 276df5aed9c245fdb34fffe959b871db [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: "276df5aed9c245fdb34fffe959b871db" member_type: VOTER }
I20260812 06:18:37.824358 11919 raft_consensus.cc:399] T 00000000000000000000000000000000 P 276df5aed9c245fdb34fffe959b871db [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:37.824398 11919 raft_consensus.cc:493] T 00000000000000000000000000000000 P 276df5aed9c245fdb34fffe959b871db [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:37.824448 11919 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 276df5aed9c245fdb34fffe959b871db [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:37.825124 11919 raft_consensus.cc:515] T 00000000000000000000000000000000 P 276df5aed9c245fdb34fffe959b871db [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "276df5aed9c245fdb34fffe959b871db" member_type: VOTER }
I20260812 06:18:37.825261 11919 leader_election.cc:304] T 00000000000000000000000000000000 P 276df5aed9c245fdb34fffe959b871db [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: 276df5aed9c245fdb34fffe959b871db; no voters: 
I20260812 06:18:37.825450 11919 leader_election.cc:290] T 00000000000000000000000000000000 P 276df5aed9c245fdb34fffe959b871db [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:37.825574 11922 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 276df5aed9c245fdb34fffe959b871db [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:37.825803 11922 raft_consensus.cc:697] T 00000000000000000000000000000000 P 276df5aed9c245fdb34fffe959b871db [term 1 LEADER]: Becoming Leader. State: Replica: 276df5aed9c245fdb34fffe959b871db, State: Running, Role: LEADER
I20260812 06:18:37.825920 11919 sys_catalog.cc:565] T 00000000000000000000000000000000 P 276df5aed9c245fdb34fffe959b871db [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:37.825950 11922 consensus_queue.cc:237] T 00000000000000000000000000000000 P 276df5aed9c245fdb34fffe959b871db [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: "276df5aed9c245fdb34fffe959b871db" member_type: VOTER }
I20260812 06:18:37.826426 11923 sys_catalog.cc:455] T 00000000000000000000000000000000 P 276df5aed9c245fdb34fffe959b871db [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "276df5aed9c245fdb34fffe959b871db" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "276df5aed9c245fdb34fffe959b871db" member_type: VOTER } }
I20260812 06:18:37.826469 11924 sys_catalog.cc:455] T 00000000000000000000000000000000 P 276df5aed9c245fdb34fffe959b871db [sys.catalog]: SysCatalogTable state changed. Reason: New leader 276df5aed9c245fdb34fffe959b871db. Latest consensus state: current_term: 1 leader_uuid: "276df5aed9c245fdb34fffe959b871db" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "276df5aed9c245fdb34fffe959b871db" member_type: VOTER } }
I20260812 06:18:37.826606 11924 sys_catalog.cc:458] T 00000000000000000000000000000000 P 276df5aed9c245fdb34fffe959b871db [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:37.826584 11923 sys_catalog.cc:458] T 00000000000000000000000000000000 P 276df5aed9c245fdb34fffe959b871db [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:37.827076 11930 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:37.827829 11930 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:37.828105 11613 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:37.829533 11930 catalog_manager.cc:1383] Generated new cluster ID: b4593f3bafe54d179505d8355c6ee8a6
I20260812 06:18:37.829587 11930 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:37.847513 11930 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:37.848038 11930 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:37.852515 11930 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 276df5aed9c245fdb34fffe959b871db: Generated new TSK 0
I20260812 06:18:37.852654 11930 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:37.860302 11613 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:37.862282 11943 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:18:37.862349 11613 server_base.cc:1061] running on GCE node
W20260812 06:18:37.862349 11945 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:18:37.862524 11948 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:18:37.862738 11613 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:37.862780 11613 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:18:37.862797 11613 hybrid_clock.cc:648] HybridClock initialized: now 1786515517862796 us; error 0 us; skew 500 ppm
I20260812 06:18:37.863613 11613 webserver.cc:533] Webserver started at http://127.11.87.65:35041/ using document root <none> and password file <none>
I20260812 06:18:37.863745 11613 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:37.863785 11613 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:37.863839 11613 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:37.864187 11613 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515512185349-11613-0/minicluster-data/ts-0-root/instance:
uuid: "f870f8a284b54b63b7f70343529f7b9c"
format_stamp: "Formatted at 2026-08-12 06:18:37 on dist-test-slave-vq2q"
I20260812 06:18:37.865633 11613 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:18:37.866537 11957 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:18:37.866751 11613 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:37.866822 11613 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515512185349-11613-0/minicluster-data/ts-0-root
uuid: "f870f8a284b54b63b7f70343529f7b9c"
format_stamp: "Formatted at 2026-08-12 06:18:37 on dist-test-slave-vq2q"
I20260812 06:18:37.866879 11613 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515512185349-11613-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515512185349-11613-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515512185349-11613-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:18:37.872277 11613 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:37.872542 11613 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:37.872776 11613 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:37.873164 11613 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:37.873234 11613 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:37.873281 11613 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:37.873299 11613 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:37.877139 11613 rpc_server.cc:307] RPC server started. Bound to: 127.11.87.65:46581
I20260812 06:18:37.878362 12033 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.11.87.65:46581 every 8 connection(s)
I20260812 06:18:37.885767 12034 heartbeater.cc:344] Connected to a master server at 127.11.87.126:36831
I20260812 06:18:37.885859 12034 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:37.886077 12034 heartbeater.cc:507] Master 127.11.87.126:36831 requested a full tablet report, sending...
I20260812 06:18:37.886685 11880 ts_manager.cc:194] Registered new tserver with Master: f870f8a284b54b63b7f70343529f7b9c (127.11.87.65:46581)
I20260812 06:18:37.887382 11880 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:57884
I20260812 06:18:37.887692 11613 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.009862568s
I20260812 06:18:37.894344 11880 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:57888:
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:18:37.902415 11990 tablet_service.cc:1511] Processing CreateTablet for tablet 627f8f6cd1de4353aa91b74e551babea (DEFAULT_TABLE table=heavy-update-compaction-test [id=bcbe8a86b3d543e1bd54302251f7c563]), partition=
I20260812 06:18:37.902683 11990 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 627f8f6cd1de4353aa91b74e551babea. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:37.905061 12049 tablet_bootstrap.cc:492] T 627f8f6cd1de4353aa91b74e551babea P f870f8a284b54b63b7f70343529f7b9c: Bootstrap starting.
I20260812 06:18:37.905994 12049 tablet_bootstrap.cc:654] T 627f8f6cd1de4353aa91b74e551babea P f870f8a284b54b63b7f70343529f7b9c: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:37.906911 12049 tablet_bootstrap.cc:492] T 627f8f6cd1de4353aa91b74e551babea P f870f8a284b54b63b7f70343529f7b9c: No bootstrap required, opened a new log
I20260812 06:18:37.906983 12049 ts_tablet_manager.cc:1403] T 627f8f6cd1de4353aa91b74e551babea P f870f8a284b54b63b7f70343529f7b9c: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:18:37.907371 12049 raft_consensus.cc:359] T 627f8f6cd1de4353aa91b74e551babea P f870f8a284b54b63b7f70343529f7b9c [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f870f8a284b54b63b7f70343529f7b9c" member_type: VOTER last_known_addr { host: "127.11.87.65" port: 46581 } }
I20260812 06:18:37.907455 12049 raft_consensus.cc:385] T 627f8f6cd1de4353aa91b74e551babea P f870f8a284b54b63b7f70343529f7b9c [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:37.907476 12049 raft_consensus.cc:740] T 627f8f6cd1de4353aa91b74e551babea P f870f8a284b54b63b7f70343529f7b9c [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: f870f8a284b54b63b7f70343529f7b9c, State: Initialized, Role: FOLLOWER
I20260812 06:18:37.907580 12049 consensus_queue.cc:260] T 627f8f6cd1de4353aa91b74e551babea P f870f8a284b54b63b7f70343529f7b9c [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: "f870f8a284b54b63b7f70343529f7b9c" member_type: VOTER last_known_addr { host: "127.11.87.65" port: 46581 } }
I20260812 06:18:37.907668 12049 raft_consensus.cc:399] T 627f8f6cd1de4353aa91b74e551babea P f870f8a284b54b63b7f70343529f7b9c [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:37.907692 12049 raft_consensus.cc:493] T 627f8f6cd1de4353aa91b74e551babea P f870f8a284b54b63b7f70343529f7b9c [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:37.907721 12049 raft_consensus.cc:3060] T 627f8f6cd1de4353aa91b74e551babea P f870f8a284b54b63b7f70343529f7b9c [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:37.908509 12049 raft_consensus.cc:515] T 627f8f6cd1de4353aa91b74e551babea P f870f8a284b54b63b7f70343529f7b9c [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f870f8a284b54b63b7f70343529f7b9c" member_type: VOTER last_known_addr { host: "127.11.87.65" port: 46581 } }
I20260812 06:18:37.908634 12049 leader_election.cc:304] T 627f8f6cd1de4353aa91b74e551babea P f870f8a284b54b63b7f70343529f7b9c [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: f870f8a284b54b63b7f70343529f7b9c; no voters: 
I20260812 06:18:37.908818 12049 leader_election.cc:290] T 627f8f6cd1de4353aa91b74e551babea P f870f8a284b54b63b7f70343529f7b9c [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:37.908924 12052 raft_consensus.cc:2804] T 627f8f6cd1de4353aa91b74e551babea P f870f8a284b54b63b7f70343529f7b9c [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:37.909101 12049 ts_tablet_manager.cc:1434] T 627f8f6cd1de4353aa91b74e551babea P f870f8a284b54b63b7f70343529f7b9c: Time spent starting tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:37.909142 12034 heartbeater.cc:499] Master 127.11.87.126:36831 was elected leader, sending a full tablet report...
I20260812 06:18:37.909119 12052 raft_consensus.cc:697] T 627f8f6cd1de4353aa91b74e551babea P f870f8a284b54b63b7f70343529f7b9c [term 1 LEADER]: Becoming Leader. State: Replica: f870f8a284b54b63b7f70343529f7b9c, State: Running, Role: LEADER
I20260812 06:18:37.909323 12052 consensus_queue.cc:237] T 627f8f6cd1de4353aa91b74e551babea P f870f8a284b54b63b7f70343529f7b9c [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: "f870f8a284b54b63b7f70343529f7b9c" member_type: VOTER last_known_addr { host: "127.11.87.65" port: 46581 } }
I20260812 06:18:37.910629 11880 catalog_manager.cc:5719] T 627f8f6cd1de4353aa91b74e551babea P f870f8a284b54b63b7f70343529f7b9c reported cstate change: term changed from 0 to 1, leader changed from <none> to f870f8a284b54b63b7f70343529f7b9c (127.11.87.65). New cstate: current_term: 1 leader_uuid: "f870f8a284b54b63b7f70343529f7b9c" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f870f8a284b54b63b7f70343529f7b9c" member_type: VOTER last_known_addr { host: "127.11.87.65" port: 46581 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:37.965848 11613 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.052s	user 0.011s	sys 0.012s
I20260812 06:18:38.128793 12035 maintenance_manager.cc:419] P f870f8a284b54b63b7f70343529f7b9c: Scheduling FlushMRSOp(627f8f6cd1de4353aa91b74e551babea): perf score=23.023690
I20260812 06:18:38.277626 11964 maintenance_manager.cc:643] P f870f8a284b54b63b7f70343529f7b9c: FlushMRSOp(627f8f6cd1de4353aa91b74e551babea) complete. Timing: real 0.149s	user 0.118s	sys 0.027s Metrics: {"bytes_written":12307490,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":67,"dirs.run_cpu_time_us":192,"dirs.run_wall_time_us":905,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":36438,"lbm_writes_lt_1ms":857,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"update_count":1500}
I20260812 06:18:38.278358 12035 maintenance_manager.cc:419] P f870f8a284b54b63b7f70343529f7b9c: Scheduling LogGCOp(627f8f6cd1de4353aa91b74e551babea): free 20743880 bytes of WAL
I20260812 06:18:38.278597 11964 log_reader.cc:385] T 627f8f6cd1de4353aa91b74e551babea: removed 2 log segments from log reader
I20260812 06:18:38.278646 11964 log.cc:1079] T 627f8f6cd1de4353aa91b74e551babea P f870f8a284b54b63b7f70343529f7b9c: Deleting log segment in path: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515512185349-11613-0/minicluster-data/ts-0-root/wals/627f8f6cd1de4353aa91b74e551babea/wal-000000001 (ops 1-6)
I20260812 06:18:38.278678 11964 log.cc:1079] T 627f8f6cd1de4353aa91b74e551babea P f870f8a284b54b63b7f70343529f7b9c: Deleting log segment in path: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515512185349-11613-0/minicluster-data/ts-0-root/wals/627f8f6cd1de4353aa91b74e551babea/wal-000000002 (ops 7-11)
I20260812 06:18:38.282193 11964 maintenance_manager.cc:643] P f870f8a284b54b63b7f70343529f7b9c: LogGCOp(627f8f6cd1de4353aa91b74e551babea) complete. Timing: real 0.004s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:18:38.282516 12035 maintenance_manager.cc:419] P f870f8a284b54b63b7f70343529f7b9c: Scheduling FlushDeltaMemStoresOp(627f8f6cd1de4353aa91b74e551babea): perf score=2.188937
I20260812 06:18:38.299201 11964 maintenance_manager.cc:643] P f870f8a284b54b63b7f70343529f7b9c: FlushDeltaMemStoresOp(627f8f6cd1de4353aa91b74e551babea) complete. Timing: real 0.017s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5470,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:38.299722 12035 maintenance_manager.cc:419] P f870f8a284b54b63b7f70343529f7b9c: Scheduling MajorDeltaCompactionOp(627f8f6cd1de4353aa91b74e551babea): perf score=1.000000
I20260812 06:18:38.458189 11964 maintenance_manager.cc:643] P f870f8a284b54b63b7f70343529f7b9c: MajorDeltaCompactionOp(627f8f6cd1de4353aa91b74e551babea) complete. Timing: real 0.158s	user 0.110s	sys 0.039s 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":584,"lbm_read_time_us":10173,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24681,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1792,"thread_start_us":295,"threads_started":5,"update_count":2000}
I20260812 06:18:38.458732 12035 maintenance_manager.cc:419] P f870f8a284b54b63b7f70343529f7b9c: Scheduling UndoDeltaBlockGCOp(627f8f6cd1de4353aa91b74e551babea): 20513813 bytes on disk
I20260812 06:18:38.459193 11964 maintenance_manager.cc:643] P f870f8a284b54b63b7f70343529f7b9c: UndoDeltaBlockGCOp(627f8f6cd1de4353aa91b74e551babea) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":45,"lbm_reads_lt_1ms":4}
I20260812 06:18:38.459602 12035 maintenance_manager.cc:419] P f870f8a284b54b63b7f70343529f7b9c: Scheduling FlushDeltaMemStoresOp(627f8f6cd1de4353aa91b74e551babea): perf score=14.095187
I20260812 06:18:38.505153 11964 maintenance_manager.cc:643] P f870f8a284b54b63b7f70343529f7b9c: FlushDeltaMemStoresOp(627f8f6cd1de4353aa91b74e551babea) complete. Timing: real 0.045s	user 0.029s	sys 0.008s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18308,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:38.505766 12035 maintenance_manager.cc:419] P f870f8a284b54b63b7f70343529f7b9c: Scheduling MajorDeltaCompactionOp(627f8f6cd1de4353aa91b74e551babea): perf score=1.000000
I20260812 06:18:38.650338 11964 maintenance_manager.cc:643] P f870f8a284b54b63b7f70343529f7b9c: MajorDeltaCompactionOp(627f8f6cd1de4353aa91b74e551babea) complete. Timing: real 0.144s	user 0.121s	sys 0.016s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713152,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":837,"lbm_read_time_us":10427,"lbm_reads_lt_1ms":463,"lbm_write_time_us":21664,"lbm_writes_lt_1ms":443,"mutex_wait_us":464,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2000}
I20260812 06:18:38.651036 12035 maintenance_manager.cc:419] P f870f8a284b54b63b7f70343529f7b9c: Scheduling FlushDeltaMemStoresOp(627f8f6cd1de4353aa91b74e551babea): perf score=14.095187
I20260812 06:18:38.709100 11964 maintenance_manager.cc:643] P f870f8a284b54b63b7f70343529f7b9c: FlushDeltaMemStoresOp(627f8f6cd1de4353aa91b74e551babea) complete. Timing: real 0.058s	user 0.015s	sys 0.039s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23360,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:38.709685 12035 maintenance_manager.cc:419] P f870f8a284b54b63b7f70343529f7b9c: Scheduling FlushDeltaMemStoresOp(627f8f6cd1de4353aa91b74e551babea): perf score=2.188937
I20260812 06:18:38.727691 11964 maintenance_manager.cc:643] P f870f8a284b54b63b7f70343529f7b9c: FlushDeltaMemStoresOp(627f8f6cd1de4353aa91b74e551babea) complete. Timing: real 0.018s	user 0.012s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4446,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:38.728240 12035 maintenance_manager.cc:419] P f870f8a284b54b63b7f70343529f7b9c: Scheduling MajorDeltaCompactionOp(627f8f6cd1de4353aa91b74e551babea): perf score=1.000000
I20260812 06:18:38.921200 11964 maintenance_manager.cc:643] P f870f8a284b54b63b7f70343529f7b9c: MajorDeltaCompactionOp(627f8f6cd1de4353aa91b74e551babea) complete. Timing: real 0.193s	user 0.100s	sys 0.087s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1067,"lbm_read_time_us":13774,"lbm_reads_lt_1ms":564,"lbm_write_time_us":31891,"lbm_writes_lt_1ms":543,"mutex_wait_us":241,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4864,"update_count":2500}
I20260812 06:18:38.921787 12035 maintenance_manager.cc:419] P f870f8a284b54b63b7f70343529f7b9c: Scheduling FlushDeltaMemStoresOp(627f8f6cd1de4353aa91b74e551babea): perf score=14.095187
I20260812 06:18:38.967553 11964 maintenance_manager.cc:643] P f870f8a284b54b63b7f70343529f7b9c: FlushDeltaMemStoresOp(627f8f6cd1de4353aa91b74e551babea) complete. Timing: real 0.046s	user 0.028s	sys 0.015s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20351,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:38.968025 12035 maintenance_manager.cc:419] P f870f8a284b54b63b7f70343529f7b9c: Scheduling FlushDeltaMemStoresOp(627f8f6cd1de4353aa91b74e551babea): perf score=2.188937
I20260812 06:18:38.978768 11964 maintenance_manager.cc:643] P f870f8a284b54b63b7f70343529f7b9c: FlushDeltaMemStoresOp(627f8f6cd1de4353aa91b74e551babea) complete. Timing: real 0.011s	user 0.000s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3991,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:38.979275 12035 maintenance_manager.cc:419] P f870f8a284b54b63b7f70343529f7b9c: Scheduling MajorDeltaCompactionOp(627f8f6cd1de4353aa91b74e551babea): perf score=1.000000
I20260812 06:18:39.127907 11964 maintenance_manager.cc:643] P f870f8a284b54b63b7f70343529f7b9c: MajorDeltaCompactionOp(627f8f6cd1de4353aa91b74e551babea) complete. Timing: real 0.148s	user 0.099s	sys 0.045s 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":199,"lbm_read_time_us":8905,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28693,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3328,"update_count":2500}
I20260812 06:18:39.128458 12035 maintenance_manager.cc:419] P f870f8a284b54b63b7f70343529f7b9c: Scheduling FlushDeltaMemStoresOp(627f8f6cd1de4353aa91b74e551babea): perf score=11.118625
I20260812 06:18:39.164357 11964 maintenance_manager.cc:643] P f870f8a284b54b63b7f70343529f7b9c: FlushDeltaMemStoresOp(627f8f6cd1de4353aa91b74e551babea) complete. Timing: real 0.036s	user 0.021s	sys 0.012s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":14783,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:39.164875 12035 maintenance_manager.cc:419] P f870f8a284b54b63b7f70343529f7b9c: Scheduling FlushDeltaMemStoresOp(627f8f6cd1de4353aa91b74e551babea): perf score=2.188937
I20260812 06:18:39.190300 11964 maintenance_manager.cc:643] P f870f8a284b54b63b7f70343529f7b9c: FlushDeltaMemStoresOp(627f8f6cd1de4353aa91b74e551babea) complete. Timing: real 0.025s	user 0.011s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5642,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:39.190762 12035 maintenance_manager.cc:419] P f870f8a284b54b63b7f70343529f7b9c: Scheduling FlushDeltaMemStoresOp(627f8f6cd1de4353aa91b74e551babea): perf score=2.188937
I20260812 06:18:39.200486 11964 maintenance_manager.cc:643] P f870f8a284b54b63b7f70343529f7b9c: FlushDeltaMemStoresOp(627f8f6cd1de4353aa91b74e551babea) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3529,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:39.200933 12035 maintenance_manager.cc:419] P f870f8a284b54b63b7f70343529f7b9c: Scheduling MajorDeltaCompactionOp(627f8f6cd1de4353aa91b74e551babea): perf score=1.000000
I20260812 06:18:39.345017 11964 maintenance_manager.cc:643] P f870f8a284b54b63b7f70343529f7b9c: MajorDeltaCompactionOp(627f8f6cd1de4353aa91b74e551babea) complete. Timing: real 0.144s	user 0.109s	sys 0.033s 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":643,"lbm_read_time_us":11749,"lbm_reads_lt_1ms":573,"lbm_write_time_us":27286,"lbm_writes_lt_1ms":543,"mutex_wait_us":274,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3072,"update_count":2500}
I20260812 06:18:39.345696 12035 maintenance_manager.cc:419] P f870f8a284b54b63b7f70343529f7b9c: Scheduling FlushDeltaMemStoresOp(627f8f6cd1de4353aa91b74e551babea): perf score=11.118625
I20260812 06:18:39.379981 11964 maintenance_manager.cc:643] P f870f8a284b54b63b7f70343529f7b9c: FlushDeltaMemStoresOp(627f8f6cd1de4353aa91b74e551babea) complete. Timing: real 0.034s	user 0.015s	sys 0.017s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":13782,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:39.380725 12035 maintenance_manager.cc:419] P f870f8a284b54b63b7f70343529f7b9c: Scheduling FlushDeltaMemStoresOp(627f8f6cd1de4353aa91b74e551babea): perf score=2.188937
I20260812 06:18:39.391788 11964 maintenance_manager.cc:643] P f870f8a284b54b63b7f70343529f7b9c: FlushDeltaMemStoresOp(627f8f6cd1de4353aa91b74e551babea) complete. Timing: real 0.011s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3571,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:39.392336 12035 maintenance_manager.cc:419] P f870f8a284b54b63b7f70343529f7b9c: Scheduling FlushMRSOp(627f8f6cd1de4353aa91b74e551babea): perf score=1.000000
I20260812 06:18:39.428330 11964 maintenance_manager.cc:643] P f870f8a284b54b63b7f70343529f7b9c: FlushMRSOp(627f8f6cd1de4353aa91b74e551babea) complete. Timing: real 0.036s	user 0.021s	sys 0.004s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":66,"dirs.run_cpu_time_us":221,"dirs.run_wall_time_us":1301,"drs_written":1,"lbm_read_time_us":43,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1796,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:39.428927 12035 maintenance_manager.cc:419] P f870f8a284b54b63b7f70343529f7b9c: Scheduling FlushDeltaMemStoresOp(627f8f6cd1de4353aa91b74e551babea): perf score=3.181125
I20260812 06:18:39.441514 11964 maintenance_manager.cc:643] P f870f8a284b54b63b7f70343529f7b9c: FlushDeltaMemStoresOp(627f8f6cd1de4353aa91b74e551babea) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":3733,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:39.441988 12035 maintenance_manager.cc:419] P f870f8a284b54b63b7f70343529f7b9c: Scheduling LogGCOp(627f8f6cd1de4353aa91b74e551babea): free 120553369 bytes of WAL
I20260812 06:18:39.442210 11964 log_reader.cc:385] T 627f8f6cd1de4353aa91b74e551babea: removed 12 log segments from log reader
I20260812 06:18:39.442255 11964 log.cc:1079] T 627f8f6cd1de4353aa91b74e551babea P f870f8a284b54b63b7f70343529f7b9c: Deleting log segment in path: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515512185349-11613-0/minicluster-data/ts-0-root/wals/627f8f6cd1de4353aa91b74e551babea/wal-000000003 (ops 12-16)
I20260812 06:18:39.442294 11964 log.cc:1079] T 627f8f6cd1de4353aa91b74e551babea P f870f8a284b54b63b7f70343529f7b9c: Deleting log segment in path: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515512185349-11613-0/minicluster-data/ts-0-root/wals/627f8f6cd1de4353aa91b74e551babea/wal-000000004 (ops 17-20)
I20260812 06:18:39.442327 11964 log.cc:1079] T 627f8f6cd1de4353aa91b74e551babea P f870f8a284b54b63b7f70343529f7b9c: Deleting log segment in path: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515512185349-11613-0/minicluster-data/ts-0-root/wals/627f8f6cd1de4353aa91b74e551babea/wal-000000005 (ops 21-25)
I20260812 06:18:39.442358 11964 log.cc:1079] T 627f8f6cd1de4353aa91b74e551babea P f870f8a284b54b63b7f70343529f7b9c: Deleting log segment in path: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515512185349-11613-0/minicluster-data/ts-0-root/wals/627f8f6cd1de4353aa91b74e551babea/wal-000000006 (ops 26-30)
I20260812 06:18:39.442395 11964 log.cc:1079] T 627f8f6cd1de4353aa91b74e551babea P f870f8a284b54b63b7f70343529f7b9c: Deleting log segment in path: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515512185349-11613-0/minicluster-data/ts-0-root/wals/627f8f6cd1de4353aa91b74e551babea/wal-000000007 (ops 31-35)
I20260812 06:18:39.442427 11964 log.cc:1079] T 627f8f6cd1de4353aa91b74e551babea P f870f8a284b54b63b7f70343529f7b9c: Deleting log segment in path: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515512185349-11613-0/minicluster-data/ts-0-root/wals/627f8f6cd1de4353aa91b74e551babea/wal-000000008 (ops 36-40)
I20260812 06:18:39.442456 11964 log.cc:1079] T 627f8f6cd1de4353aa91b74e551babea P f870f8a284b54b63b7f70343529f7b9c: Deleting log segment in path: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515512185349-11613-0/minicluster-data/ts-0-root/wals/627f8f6cd1de4353aa91b74e551babea/wal-000000009 (ops 41-44)
I20260812 06:18:39.442487 11964 log.cc:1079] T 627f8f6cd1de4353aa91b74e551babea P f870f8a284b54b63b7f70343529f7b9c: Deleting log segment in path: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515512185349-11613-0/minicluster-data/ts-0-root/wals/627f8f6cd1de4353aa91b74e551babea/wal-000000010 (ops 45-49)
I20260812 06:18:39.442517 11964 log.cc:1079] T 627f8f6cd1de4353aa91b74e551babea P f870f8a284b54b63b7f70343529f7b9c: Deleting log segment in path: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515512185349-11613-0/minicluster-data/ts-0-root/wals/627f8f6cd1de4353aa91b74e551babea/wal-000000011 (ops 50-54)
I20260812 06:18:39.442545 11964 log.cc:1079] T 627f8f6cd1de4353aa91b74e551babea P f870f8a284b54b63b7f70343529f7b9c: Deleting log segment in path: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515512185349-11613-0/minicluster-data/ts-0-root/wals/627f8f6cd1de4353aa91b74e551babea/wal-000000012 (ops 55-59)
I20260812 06:18:39.442575 11964 log.cc:1079] T 627f8f6cd1de4353aa91b74e551babea P f870f8a284b54b63b7f70343529f7b9c: Deleting log segment in path: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515512185349-11613-0/minicluster-data/ts-0-root/wals/627f8f6cd1de4353aa91b74e551babea/wal-000000013 (ops 60-64)
I20260812 06:18:39.442605 11964 log.cc:1079] T 627f8f6cd1de4353aa91b74e551babea P f870f8a284b54b63b7f70343529f7b9c: Deleting log segment in path: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515512185349-11613-0/minicluster-data/ts-0-root/wals/627f8f6cd1de4353aa91b74e551babea/wal-000000014 (ops 65-69)
I20260812 06:18:39.462976 11964 maintenance_manager.cc:643] P f870f8a284b54b63b7f70343529f7b9c: LogGCOp(627f8f6cd1de4353aa91b74e551babea) complete. Timing: real 0.021s	user 0.001s	sys 0.018s Metrics: {}
I20260812 06:18:39.463454 12035 maintenance_manager.cc:419] P f870f8a284b54b63b7f70343529f7b9c: Scheduling UndoDeltaBlockGCOp(627f8f6cd1de4353aa91b74e551babea): 447 bytes on disk
I20260812 06:18:39.463879 11964 maintenance_manager.cc:643] P f870f8a284b54b63b7f70343529f7b9c: UndoDeltaBlockGCOp(627f8f6cd1de4353aa91b74e551babea) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4}
I20260812 06:18:39.464398 12035 maintenance_manager.cc:419] P f870f8a284b54b63b7f70343529f7b9c: Scheduling FlushDeltaMemStoresOp(627f8f6cd1de4353aa91b74e551babea): perf score=2.188937
I20260812 06:18:39.484790 11964 maintenance_manager.cc:643] P f870f8a284b54b63b7f70343529f7b9c: FlushDeltaMemStoresOp(627f8f6cd1de4353aa91b74e551babea) complete. Timing: real 0.020s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5668,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:39.485272 12035 maintenance_manager.cc:419] P f870f8a284b54b63b7f70343529f7b9c: Scheduling FlushDeltaMemStoresOp(627f8f6cd1de4353aa91b74e551babea): perf score=2.188937
I20260812 06:18:39.502548 11964 maintenance_manager.cc:643] P f870f8a284b54b63b7f70343529f7b9c: FlushDeltaMemStoresOp(627f8f6cd1de4353aa91b74e551babea) complete. Timing: real 0.017s	user 0.008s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3297,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:39.503082 12035 maintenance_manager.cc:419] P f870f8a284b54b63b7f70343529f7b9c: Scheduling MajorDeltaCompactionOp(627f8f6cd1de4353aa91b74e551babea): perf score=1.000000
I20260812 06:18:39.742849 11964 maintenance_manager.cc:643] P f870f8a284b54b63b7f70343529f7b9c: MajorDeltaCompactionOp(627f8f6cd1de4353aa91b74e551babea) complete. Timing: real 0.240s	user 0.181s	sys 0.056s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":33020845,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":439,"lbm_read_time_us":16422,"lbm_reads_lt_1ms":775,"lbm_write_time_us":37118,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":3840,"thread_start_us":85,"threads_started":1,"update_count":3500}
I20260812 06:18:39.743492 12035 maintenance_manager.cc:419] P f870f8a284b54b63b7f70343529f7b9c: Scheduling FlushDeltaMemStoresOp(627f8f6cd1de4353aa91b74e551babea): perf score=15.087375
I20260812 06:18:39.798780 11964 maintenance_manager.cc:643] P f870f8a284b54b63b7f70343529f7b9c: FlushDeltaMemStoresOp(627f8f6cd1de4353aa91b74e551babea) complete. Timing: real 0.055s	user 0.040s	sys 0.008s Metrics: {"bytes_written":16820145,"delete_count":0,"lbm_write_time_us":20160,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:18:39.799295 12035 maintenance_manager.cc:419] P f870f8a284b54b63b7f70343529f7b9c: Scheduling FlushDeltaMemStoresOp(627f8f6cd1de4353aa91b74e551babea): perf score=2.188937
I20260812 06:18:39.821024 11964 maintenance_manager.cc:643] P f870f8a284b54b63b7f70343529f7b9c: FlushDeltaMemStoresOp(627f8f6cd1de4353aa91b74e551babea) complete. Timing: real 0.022s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5124,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:39.821539 12035 maintenance_manager.cc:419] P f870f8a284b54b63b7f70343529f7b9c: Scheduling FlushDeltaMemStoresOp(627f8f6cd1de4353aa91b74e551babea): perf score=2.188937
I20260812 06:18:39.831279 11964 maintenance_manager.cc:643] P f870f8a284b54b63b7f70343529f7b9c: FlushDeltaMemStoresOp(627f8f6cd1de4353aa91b74e551babea) complete. Timing: real 0.010s	user 0.004s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3524,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:39.831828 12035 maintenance_manager.cc:419] P f870f8a284b54b63b7f70343529f7b9c: Scheduling MajorDeltaCompactionOp(627f8f6cd1de4353aa91b74e551babea): perf score=1.000000
I20260812 06:18:40.036935 11964 maintenance_manager.cc:643] P f870f8a284b54b63b7f70343529f7b9c: MajorDeltaCompactionOp(627f8f6cd1de4353aa91b74e551babea) complete. Timing: real 0.205s	user 0.120s	sys 0.084s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918204,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":706,"lbm_read_time_us":13053,"lbm_reads_lt_1ms":673,"lbm_write_time_us":31677,"lbm_writes_lt_1ms":643,"mutex_wait_us":315,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":22272,"update_count":3000}
I20260812 06:18:40.037639 12035 maintenance_manager.cc:419] P f870f8a284b54b63b7f70343529f7b9c: Scheduling FlushDeltaMemStoresOp(627f8f6cd1de4353aa91b74e551babea): perf score=14.095187
I20260812 06:18:40.085397 11964 maintenance_manager.cc:643] P f870f8a284b54b63b7f70343529f7b9c: FlushDeltaMemStoresOp(627f8f6cd1de4353aa91b74e551babea) complete. Timing: real 0.048s	user 0.038s	sys 0.005s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":18973,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:40.086028 12035 maintenance_manager.cc:419] P f870f8a284b54b63b7f70343529f7b9c: Scheduling MajorDeltaCompactionOp(627f8f6cd1de4353aa91b74e551babea): perf score=1.000000
I20260812 06:18:40.232729 11964 maintenance_manager.cc:643] P f870f8a284b54b63b7f70343529f7b9c: MajorDeltaCompactionOp(627f8f6cd1de4353aa91b74e551babea) complete. Timing: real 0.147s	user 0.074s	sys 0.065s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713153,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":181,"lbm_read_time_us":10452,"lbm_reads_lt_1ms":463,"lbm_write_time_us":22070,"lbm_writes_lt_1ms":443,"mutex_wait_us":44,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":47232,"update_count":2000}
I20260812 06:18:40.233309 12035 maintenance_manager.cc:419] P f870f8a284b54b63b7f70343529f7b9c: Scheduling FlushDeltaMemStoresOp(627f8f6cd1de4353aa91b74e551babea): perf score=14.095187
I20260812 06:18:40.288782 11964 maintenance_manager.cc:643] P f870f8a284b54b63b7f70343529f7b9c: FlushDeltaMemStoresOp(627f8f6cd1de4353aa91b74e551babea) complete. Timing: real 0.055s	user 0.017s	sys 0.024s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19813,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:40.289357 12035 maintenance_manager.cc:419] P f870f8a284b54b63b7f70343529f7b9c: Scheduling FlushDeltaMemStoresOp(627f8f6cd1de4353aa91b74e551babea): perf score=2.188937
I20260812 06:18:40.300140 11964 maintenance_manager.cc:643] P f870f8a284b54b63b7f70343529f7b9c: FlushDeltaMemStoresOp(627f8f6cd1de4353aa91b74e551babea) complete. Timing: real 0.011s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3842,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:40.300616 12035 maintenance_manager.cc:419] P f870f8a284b54b63b7f70343529f7b9c: Scheduling MajorDeltaCompactionOp(627f8f6cd1de4353aa91b74e551babea): perf score=1.000000
I20260812 06:18:40.470387 11964 maintenance_manager.cc:643] P f870f8a284b54b63b7f70343529f7b9c: MajorDeltaCompactionOp(627f8f6cd1de4353aa91b74e551babea) complete. Timing: real 0.170s	user 0.106s	sys 0.052s 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":297,"lbm_read_time_us":9593,"lbm_reads_lt_1ms":572,"lbm_write_time_us":23992,"lbm_writes_lt_1ms":543,"mutex_wait_us":54,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2500}
I20260812 06:18:40.470906 12035 maintenance_manager.cc:419] P f870f8a284b54b63b7f70343529f7b9c: Scheduling FlushDeltaMemStoresOp(627f8f6cd1de4353aa91b74e551babea): perf score=14.095187
I20260812 06:18:40.521880 11964 maintenance_manager.cc:643] P f870f8a284b54b63b7f70343529f7b9c: FlushDeltaMemStoresOp(627f8f6cd1de4353aa91b74e551babea) complete. Timing: real 0.051s	user 0.027s	sys 0.015s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":18528,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:40.522445 12035 maintenance_manager.cc:419] P f870f8a284b54b63b7f70343529f7b9c: Scheduling FlushDeltaMemStoresOp(627f8f6cd1de4353aa91b74e551babea): perf score=2.188937
I20260812 06:18:40.533701 11964 maintenance_manager.cc:643] P f870f8a284b54b63b7f70343529f7b9c: FlushDeltaMemStoresOp(627f8f6cd1de4353aa91b74e551babea) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4055,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:40.534173 12035 maintenance_manager.cc:419] P f870f8a284b54b63b7f70343529f7b9c: Scheduling MajorDeltaCompactionOp(627f8f6cd1de4353aa91b74e551babea): perf score=1.000000
I20260812 06:18:40.669615 11964 maintenance_manager.cc:643] P f870f8a284b54b63b7f70343529f7b9c: MajorDeltaCompactionOp(627f8f6cd1de4353aa91b74e551babea) complete. Timing: real 0.135s	user 0.105s	sys 0.030s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815681,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":505,"lbm_read_time_us":9184,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27903,"lbm_writes_lt_1ms":543,"mutex_wait_us":228,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":19584,"update_count":2500}
I20260812 06:18:40.670166 12035 maintenance_manager.cc:419] P f870f8a284b54b63b7f70343529f7b9c: Scheduling FlushDeltaMemStoresOp(627f8f6cd1de4353aa91b74e551babea): perf score=10.126437
I20260812 06:18:40.709975 11964 maintenance_manager.cc:643] P f870f8a284b54b63b7f70343529f7b9c: FlushDeltaMemStoresOp(627f8f6cd1de4353aa91b74e551babea) complete. Timing: real 0.040s	user 0.018s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15991,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:18:40.710777 12035 maintenance_manager.cc:419] P f870f8a284b54b63b7f70343529f7b9c: Scheduling FlushDeltaMemStoresOp(627f8f6cd1de4353aa91b74e551babea): perf score=2.188937
I20260812 06:18:40.735456 11964 maintenance_manager.cc:643] P f870f8a284b54b63b7f70343529f7b9c: FlushDeltaMemStoresOp(627f8f6cd1de4353aa91b74e551babea) complete. Timing: real 0.024s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5012,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:40.735961 12035 maintenance_manager.cc:419] P f870f8a284b54b63b7f70343529f7b9c: Scheduling FlushDeltaMemStoresOp(627f8f6cd1de4353aa91b74e551babea): perf score=2.188937
I20260812 06:18:40.745967 11964 maintenance_manager.cc:643] P f870f8a284b54b63b7f70343529f7b9c: FlushDeltaMemStoresOp(627f8f6cd1de4353aa91b74e551babea) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3553,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:40.746428 12035 maintenance_manager.cc:419] P f870f8a284b54b63b7f70343529f7b9c: Scheduling MajorDeltaCompactionOp(627f8f6cd1de4353aa91b74e551babea): perf score=1.000000
I20260812 06:18:40.893889 11964 maintenance_manager.cc:643] P f870f8a284b54b63b7f70343529f7b9c: MajorDeltaCompactionOp(627f8f6cd1de4353aa91b74e551babea) complete. Timing: real 0.147s	user 0.110s	sys 0.035s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815803,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":928,"lbm_read_time_us":11634,"lbm_reads_lt_1ms":573,"lbm_write_time_us":26637,"lbm_writes_lt_1ms":543,"mutex_wait_us":252,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4864,"update_count":2500}
I20260812 06:18:40.894482 12035 maintenance_manager.cc:419] P f870f8a284b54b63b7f70343529f7b9c: Scheduling FlushDeltaMemStoresOp(627f8f6cd1de4353aa91b74e551babea): perf score=11.118625
I20260812 06:18:40.929968 11964 maintenance_manager.cc:643] P f870f8a284b54b63b7f70343529f7b9c: FlushDeltaMemStoresOp(627f8f6cd1de4353aa91b74e551babea) complete. Timing: real 0.035s	user 0.027s	sys 0.007s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":14653,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:40.930821 12035 maintenance_manager.cc:419] P f870f8a284b54b63b7f70343529f7b9c: Scheduling FlushDeltaMemStoresOp(627f8f6cd1de4353aa91b74e551babea): perf score=2.188937
I20260812 06:18:40.947381 11964 maintenance_manager.cc:643] P f870f8a284b54b63b7f70343529f7b9c: FlushDeltaMemStoresOp(627f8f6cd1de4353aa91b74e551babea) complete. Timing: real 0.016s	user 0.003s	sys 0.009s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4361,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:40.947921 12035 maintenance_manager.cc:419] P f870f8a284b54b63b7f70343529f7b9c: Scheduling FlushMRSOp(627f8f6cd1de4353aa91b74e551babea): perf score=1.000000
I20260812 06:18:40.997928 11964 maintenance_manager.cc:643] P f870f8a284b54b63b7f70343529f7b9c: FlushMRSOp(627f8f6cd1de4353aa91b74e551babea) complete. Timing: real 0.050s	user 0.024s	sys 0.005s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":54,"dirs.run_cpu_time_us":255,"dirs.run_wall_time_us":1406,"drs_written":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2387,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:18:40.998785 12035 maintenance_manager.cc:419] P f870f8a284b54b63b7f70343529f7b9c: Scheduling LogGCOp(627f8f6cd1de4353aa91b74e551babea): free 121006439 bytes of WAL
I20260812 06:18:40.999034 11964 log_reader.cc:385] T 627f8f6cd1de4353aa91b74e551babea: removed 12 log segments from log reader
I20260812 06:18:40.999081 11964 log.cc:1079] T 627f8f6cd1de4353aa91b74e551babea P f870f8a284b54b63b7f70343529f7b9c: Deleting log segment in path: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515512185349-11613-0/minicluster-data/ts-0-root/wals/627f8f6cd1de4353aa91b74e551babea/wal-000000015 (ops 70-74)
I20260812 06:18:40.999111 11964 log.cc:1079] T 627f8f6cd1de4353aa91b74e551babea P f870f8a284b54b63b7f70343529f7b9c: Deleting log segment in path: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515512185349-11613-0/minicluster-data/ts-0-root/wals/627f8f6cd1de4353aa91b74e551babea/wal-000000016 (ops 75-78)
I20260812 06:18:40.999142 11964 log.cc:1079] T 627f8f6cd1de4353aa91b74e551babea P f870f8a284b54b63b7f70343529f7b9c: Deleting log segment in path: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515512185349-11613-0/minicluster-data/ts-0-root/wals/627f8f6cd1de4353aa91b74e551babea/wal-000000017 (ops 79-83)
I20260812 06:18:40.999174 11964 log.cc:1079] T 627f8f6cd1de4353aa91b74e551babea P f870f8a284b54b63b7f70343529f7b9c: Deleting log segment in path: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515512185349-11613-0/minicluster-data/ts-0-root/wals/627f8f6cd1de4353aa91b74e551babea/wal-000000018 (ops 84-88)
I20260812 06:18:40.999208 11964 log.cc:1079] T 627f8f6cd1de4353aa91b74e551babea P f870f8a284b54b63b7f70343529f7b9c: Deleting log segment in path: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515512185349-11613-0/minicluster-data/ts-0-root/wals/627f8f6cd1de4353aa91b74e551babea/wal-000000019 (ops 89-93)
I20260812 06:18:40.999241 11964 log.cc:1079] T 627f8f6cd1de4353aa91b74e551babea P f870f8a284b54b63b7f70343529f7b9c: Deleting log segment in path: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515512185349-11613-0/minicluster-data/ts-0-root/wals/627f8f6cd1de4353aa91b74e551babea/wal-000000020 (ops 94-98)
I20260812 06:18:40.999269 11964 log.cc:1079] T 627f8f6cd1de4353aa91b74e551babea P f870f8a284b54b63b7f70343529f7b9c: Deleting log segment in path: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515512185349-11613-0/minicluster-data/ts-0-root/wals/627f8f6cd1de4353aa91b74e551babea/wal-000000021 (ops 99-103)
I20260812 06:18:40.999293 11964 log.cc:1079] T 627f8f6cd1de4353aa91b74e551babea P f870f8a284b54b63b7f70343529f7b9c: Deleting log segment in path: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515512185349-11613-0/minicluster-data/ts-0-root/wals/627f8f6cd1de4353aa91b74e551babea/wal-000000022 (ops 104-108)
I20260812 06:18:40.999312 11964 log.cc:1079] T 627f8f6cd1de4353aa91b74e551babea P f870f8a284b54b63b7f70343529f7b9c: Deleting log segment in path: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515512185349-11613-0/minicluster-data/ts-0-root/wals/627f8f6cd1de4353aa91b74e551babea/wal-000000023 (ops 109-113)
I20260812 06:18:40.999327 11964 log.cc:1079] T 627f8f6cd1de4353aa91b74e551babea P f870f8a284b54b63b7f70343529f7b9c: Deleting log segment in path: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515512185349-11613-0/minicluster-data/ts-0-root/wals/627f8f6cd1de4353aa91b74e551babea/wal-000000024 (ops 114-118)
I20260812 06:18:40.999343 11964 log.cc:1079] T 627f8f6cd1de4353aa91b74e551babea P f870f8a284b54b63b7f70343529f7b9c: Deleting log segment in path: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515512185349-11613-0/minicluster-data/ts-0-root/wals/627f8f6cd1de4353aa91b74e551babea/wal-000000025 (ops 119-123)
I20260812 06:18:40.999365 11964 log.cc:1079] T 627f8f6cd1de4353aa91b74e551babea P f870f8a284b54b63b7f70343529f7b9c: Deleting log segment in path: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515512185349-11613-0/minicluster-data/ts-0-root/wals/627f8f6cd1de4353aa91b74e551babea/wal-000000026 (ops 124-128)
I20260812 06:18:41.019999 11964 maintenance_manager.cc:643] P f870f8a284b54b63b7f70343529f7b9c: LogGCOp(627f8f6cd1de4353aa91b74e551babea) complete. Timing: real 0.021s	user 0.000s	sys 0.018s Metrics: {}
I20260812 06:18:41.020484 12035 maintenance_manager.cc:419] P f870f8a284b54b63b7f70343529f7b9c: Scheduling FlushDeltaMemStoresOp(627f8f6cd1de4353aa91b74e551babea): perf score=6.157687
I20260812 06:18:41.042344 11964 maintenance_manager.cc:643] P f870f8a284b54b63b7f70343529f7b9c: FlushDeltaMemStoresOp(627f8f6cd1de4353aa91b74e551babea) complete. Timing: real 0.022s	user 0.020s	sys 0.000s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":9076,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:18:41.042827 12035 maintenance_manager.cc:419] P f870f8a284b54b63b7f70343529f7b9c: Scheduling LogGCOp(627f8f6cd1de4353aa91b74e551babea): free 12017947 bytes of WAL
I20260812 06:18:41.043027 11964 log_reader.cc:385] T 627f8f6cd1de4353aa91b74e551babea: removed 1 log segments from log reader
I20260812 06:18:41.043072 11964 log.cc:1079] T 627f8f6cd1de4353aa91b74e551babea P f870f8a284b54b63b7f70343529f7b9c: Deleting log segment in path: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515512185349-11613-0/minicluster-data/ts-0-root/wals/627f8f6cd1de4353aa91b74e551babea/wal-000000027 (ops 129-133)
I20260812 06:18:41.044909 11964 maintenance_manager.cc:643] P f870f8a284b54b63b7f70343529f7b9c: LogGCOp(627f8f6cd1de4353aa91b74e551babea) complete. Timing: real 0.002s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:18:41.045248 12035 maintenance_manager.cc:419] P f870f8a284b54b63b7f70343529f7b9c: Scheduling UndoDeltaBlockGCOp(627f8f6cd1de4353aa91b74e551babea): 493 bytes on disk
I20260812 06:18:41.045642 11964 maintenance_manager.cc:643] P f870f8a284b54b63b7f70343529f7b9c: UndoDeltaBlockGCOp(627f8f6cd1de4353aa91b74e551babea) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4}
I20260812 06:18:41.046123 12035 maintenance_manager.cc:419] P f870f8a284b54b63b7f70343529f7b9c: Scheduling FlushDeltaMemStoresOp(627f8f6cd1de4353aa91b74e551babea): perf score=2.188937
I20260812 06:18:41.071990 11964 maintenance_manager.cc:643] P f870f8a284b54b63b7f70343529f7b9c: FlushDeltaMemStoresOp(627f8f6cd1de4353aa91b74e551babea) complete. Timing: real 0.026s	user 0.008s	sys 0.010s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5146,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:41.072698 12035 maintenance_manager.cc:419] P f870f8a284b54b63b7f70343529f7b9c: Scheduling MajorDeltaCompactionOp(627f8f6cd1de4353aa91b74e551babea): perf score=1.000000
I20260812 06:18:41.293604 11964 maintenance_manager.cc:643] P f870f8a284b54b63b7f70343529f7b9c: MajorDeltaCompactionOp(627f8f6cd1de4353aa91b74e551babea) complete. Timing: real 0.221s	user 0.146s	sys 0.072s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020737,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":586,"lbm_read_time_us":17172,"lbm_reads_lt_1ms":766,"lbm_write_time_us":34473,"lbm_writes_lt_1ms":743,"mutex_wait_us":492,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":12160,"thread_start_us":81,"threads_started":1,"update_count":3500}
I20260812 06:18:41.294193 12035 maintenance_manager.cc:419] P f870f8a284b54b63b7f70343529f7b9c: Scheduling FlushDeltaMemStoresOp(627f8f6cd1de4353aa91b74e551babea): perf score=18.063937
I20260812 06:18:41.357753 11964 maintenance_manager.cc:643] P f870f8a284b54b63b7f70343529f7b9c: FlushDeltaMemStoresOp(627f8f6cd1de4353aa91b74e551babea) complete. Timing: real 0.063s	user 0.040s	sys 0.019s Metrics: {"bytes_written":20512318,"delete_count":0,"lbm_write_time_us":26356,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":501,"reinsert_count":0,"update_count":2500}
I20260812 06:18:41.358325 12035 maintenance_manager.cc:419] P f870f8a284b54b63b7f70343529f7b9c: Scheduling FlushDeltaMemStoresOp(627f8f6cd1de4353aa91b74e551babea): perf score=2.188937
I20260812 06:18:41.379251 11964 maintenance_manager.cc:643] P f870f8a284b54b63b7f70343529f7b9c: FlushDeltaMemStoresOp(627f8f6cd1de4353aa91b74e551babea) complete. Timing: real 0.021s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4143684,"delete_count":0,"lbm_write_time_us":5885,"lbm_writes_lt_1ms":104,"reinsert_count":0,"update_count":505}
I20260812 06:18:41.379704 12035 maintenance_manager.cc:419] P f870f8a284b54b63b7f70343529f7b9c: Scheduling FlushDeltaMemStoresOp(627f8f6cd1de4353aa91b74e551babea): perf score=2.188937
I20260812 06:18:41.390113 11964 maintenance_manager.cc:643] P f870f8a284b54b63b7f70343529f7b9c: FlushDeltaMemStoresOp(627f8f6cd1de4353aa91b74e551babea) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4061634,"delete_count":0,"lbm_write_time_us":3870,"lbm_writes_lt_1ms":102,"reinsert_count":0,"update_count":495}
I20260812 06:18:41.390588 12035 maintenance_manager.cc:419] P f870f8a284b54b63b7f70343529f7b9c: Scheduling MajorDeltaCompactionOp(627f8f6cd1de4353aa91b74e551babea): perf score=1.000000
I20260812 06:18:41.604327 11964 maintenance_manager.cc:643] P f870f8a284b54b63b7f70343529f7b9c: MajorDeltaCompactionOp(627f8f6cd1de4353aa91b74e551babea) complete. Timing: real 0.214s	user 0.138s	sys 0.063s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":33020631,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":269,"lbm_read_time_us":14252,"lbm_reads_lt_1ms":773,"lbm_write_time_us":34717,"lbm_writes_lt_1ms":743,"mutex_wait_us":74,"peak_mem_usage":87969044,"reinsert_count":0,"update_count":3500}
I20260812 06:18:41.604962 12035 maintenance_manager.cc:419] P f870f8a284b54b63b7f70343529f7b9c: Scheduling FlushDeltaMemStoresOp(627f8f6cd1de4353aa91b74e551babea): perf score=18.063937
I20260812 06:18:41.665827 11964 maintenance_manager.cc:643] P f870f8a284b54b63b7f70343529f7b9c: FlushDeltaMemStoresOp(627f8f6cd1de4353aa91b74e551babea) complete. Timing: real 0.061s	user 0.035s	sys 0.024s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":26239,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:41.666320 12035 maintenance_manager.cc:419] P f870f8a284b54b63b7f70343529f7b9c: Scheduling FlushDeltaMemStoresOp(627f8f6cd1de4353aa91b74e551babea): perf score=2.188937
I20260812 06:18:41.678193 11964 maintenance_manager.cc:643] P f870f8a284b54b63b7f70343529f7b9c: FlushDeltaMemStoresOp(627f8f6cd1de4353aa91b74e551babea) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4084,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:41.678960 12035 maintenance_manager.cc:419] P f870f8a284b54b63b7f70343529f7b9c: Scheduling MajorDeltaCompactionOp(627f8f6cd1de4353aa91b74e551babea): perf score=1.000000
I20260812 06:18:41.876538 11964 maintenance_manager.cc:643] P f870f8a284b54b63b7f70343529f7b9c: MajorDeltaCompactionOp(627f8f6cd1de4353aa91b74e551babea) complete. Timing: real 0.197s	user 0.122s	sys 0.073s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918098,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1432,"lbm_read_time_us":13676,"lbm_reads_lt_1ms":672,"lbm_write_time_us":33529,"lbm_writes_lt_1ms":643,"mutex_wait_us":286,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":12160,"update_count":3000}
I20260812 06:18:41.877127 12035 maintenance_manager.cc:419] P f870f8a284b54b63b7f70343529f7b9c: Scheduling FlushDeltaMemStoresOp(627f8f6cd1de4353aa91b74e551babea): perf score=14.095187
I20260812 06:18:41.937908 11964 maintenance_manager.cc:643] P f870f8a284b54b63b7f70343529f7b9c: FlushDeltaMemStoresOp(627f8f6cd1de4353aa91b74e551babea) complete. Timing: real 0.061s	user 0.036s	sys 0.018s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":24119,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:41.938453 12035 maintenance_manager.cc:419] P f870f8a284b54b63b7f70343529f7b9c: Scheduling FlushDeltaMemStoresOp(627f8f6cd1de4353aa91b74e551babea): perf score=3.181125
I20260812 06:18:41.955746 11964 maintenance_manager.cc:643] P f870f8a284b54b63b7f70343529f7b9c: FlushDeltaMemStoresOp(627f8f6cd1de4353aa91b74e551babea) complete. Timing: real 0.017s	user 0.012s	sys 0.004s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":6983,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:41.956278 12035 maintenance_manager.cc:419] P f870f8a284b54b63b7f70343529f7b9c: Scheduling FlushDeltaMemStoresOp(627f8f6cd1de4353aa91b74e551babea): perf score=2.188937
I20260812 06:18:41.966064 11964 maintenance_manager.cc:643] P f870f8a284b54b63b7f70343529f7b9c: FlushDeltaMemStoresOp(627f8f6cd1de4353aa91b74e551babea) complete. Timing: real 0.010s	user 0.004s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3434,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:41.966921 12035 maintenance_manager.cc:419] P f870f8a284b54b63b7f70343529f7b9c: Scheduling MajorDeltaCompactionOp(627f8f6cd1de4353aa91b74e551babea): perf score=1.000000
I20260812 06:18:42.128230 11964 maintenance_manager.cc:643] P f870f8a284b54b63b7f70343529f7b9c: MajorDeltaCompactionOp(627f8f6cd1de4353aa91b74e551babea) complete. Timing: real 0.161s	user 0.119s	sys 0.041s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918206,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":613,"lbm_read_time_us":12605,"lbm_reads_lt_1ms":673,"lbm_write_time_us":30520,"lbm_writes_lt_1ms":643,"mutex_wait_us":313,"peak_mem_usage":75542472,"reinsert_count":0,"update_count":3000}
I20260812 06:18:42.129149 12035 maintenance_manager.cc:419] P f870f8a284b54b63b7f70343529f7b9c: Scheduling FlushDeltaMemStoresOp(627f8f6cd1de4353aa91b74e551babea): perf score=14.095187
I20260812 06:18:42.180510 11964 maintenance_manager.cc:643] P f870f8a284b54b63b7f70343529f7b9c: FlushDeltaMemStoresOp(627f8f6cd1de4353aa91b74e551babea) complete. Timing: real 0.051s	user 0.018s	sys 0.029s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23019,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:42.181166 12035 maintenance_manager.cc:419] P f870f8a284b54b63b7f70343529f7b9c: Scheduling FlushDeltaMemStoresOp(627f8f6cd1de4353aa91b74e551babea): perf score=2.188937
I20260812 06:18:42.196610 11964 maintenance_manager.cc:643] P f870f8a284b54b63b7f70343529f7b9c: FlushDeltaMemStoresOp(627f8f6cd1de4353aa91b74e551babea) complete. Timing: real 0.015s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4843,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:42.197141 12035 maintenance_manager.cc:419] P f870f8a284b54b63b7f70343529f7b9c: Scheduling MajorDeltaCompactionOp(627f8f6cd1de4353aa91b74e551babea): perf score=1.000000
I20260812 06:18:42.344411 11964 maintenance_manager.cc:643] P f870f8a284b54b63b7f70343529f7b9c: MajorDeltaCompactionOp(627f8f6cd1de4353aa91b74e551babea) complete. Timing: real 0.147s	user 0.121s	sys 0.024s 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":236,"lbm_read_time_us":8541,"lbm_reads_lt_1ms":564,"lbm_write_time_us":29783,"lbm_writes_lt_1ms":543,"mutex_wait_us":35,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7168,"update_count":2500}
I20260812 06:18:42.345104 12035 maintenance_manager.cc:419] P f870f8a284b54b63b7f70343529f7b9c: Scheduling FlushDeltaMemStoresOp(627f8f6cd1de4353aa91b74e551babea): perf score=14.095187
I20260812 06:18:42.411392 11964 maintenance_manager.cc:643] P f870f8a284b54b63b7f70343529f7b9c: FlushDeltaMemStoresOp(627f8f6cd1de4353aa91b74e551babea) complete. Timing: real 0.066s	user 0.026s	sys 0.028s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":27192,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:18:42.412070 12035 maintenance_manager.cc:419] P f870f8a284b54b63b7f70343529f7b9c: Scheduling FlushDeltaMemStoresOp(627f8f6cd1de4353aa91b74e551babea): perf score=2.188937
I20260812 06:18:42.424477 11964 maintenance_manager.cc:643] P f870f8a284b54b63b7f70343529f7b9c: FlushDeltaMemStoresOp(627f8f6cd1de4353aa91b74e551babea) complete. Timing: real 0.012s	user 0.003s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4704,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:42.425019 12035 maintenance_manager.cc:419] P f870f8a284b54b63b7f70343529f7b9c: Scheduling FlushMRSOp(627f8f6cd1de4353aa91b74e551babea): perf score=1.000000
I20260812 06:18:42.456991 11964 maintenance_manager.cc:643] P f870f8a284b54b63b7f70343529f7b9c: FlushMRSOp(627f8f6cd1de4353aa91b74e551babea) complete. Timing: real 0.032s	user 0.030s	sys 0.000s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":63,"dirs.run_cpu_time_us":231,"dirs.run_wall_time_us":1301,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2116,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:18:42.457772 12035 maintenance_manager.cc:419] P f870f8a284b54b63b7f70343529f7b9c: Scheduling LogGCOp(627f8f6cd1de4353aa91b74e551babea): free 120553588 bytes of WAL
I20260812 06:18:42.458010 11964 log_reader.cc:385] T 627f8f6cd1de4353aa91b74e551babea: removed 12 log segments from log reader
I20260812 06:18:42.458057 11964 log.cc:1079] T 627f8f6cd1de4353aa91b74e551babea P f870f8a284b54b63b7f70343529f7b9c: Deleting log segment in path: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515512185349-11613-0/minicluster-data/ts-0-root/wals/627f8f6cd1de4353aa91b74e551babea/wal-000000028 (ops 134-138)
I20260812 06:18:42.458097 11964 log.cc:1079] T 627f8f6cd1de4353aa91b74e551babea P f870f8a284b54b63b7f70343529f7b9c: Deleting log segment in path: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515512185349-11613-0/minicluster-data/ts-0-root/wals/627f8f6cd1de4353aa91b74e551babea/wal-000000029 (ops 139-142)
I20260812 06:18:42.458132 11964 log.cc:1079] T 627f8f6cd1de4353aa91b74e551babea P f870f8a284b54b63b7f70343529f7b9c: Deleting log segment in path: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515512185349-11613-0/minicluster-data/ts-0-root/wals/627f8f6cd1de4353aa91b74e551babea/wal-000000030 (ops 143-147)
I20260812 06:18:42.458163 11964 log.cc:1079] T 627f8f6cd1de4353aa91b74e551babea P f870f8a284b54b63b7f70343529f7b9c: Deleting log segment in path: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515512185349-11613-0/minicluster-data/ts-0-root/wals/627f8f6cd1de4353aa91b74e551babea/wal-000000031 (ops 148-152)
I20260812 06:18:42.458194 11964 log.cc:1079] T 627f8f6cd1de4353aa91b74e551babea P f870f8a284b54b63b7f70343529f7b9c: Deleting log segment in path: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515512185349-11613-0/minicluster-data/ts-0-root/wals/627f8f6cd1de4353aa91b74e551babea/wal-000000032 (ops 153-157)
I20260812 06:18:42.458225 11964 log.cc:1079] T 627f8f6cd1de4353aa91b74e551babea P f870f8a284b54b63b7f70343529f7b9c: Deleting log segment in path: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515512185349-11613-0/minicluster-data/ts-0-root/wals/627f8f6cd1de4353aa91b74e551babea/wal-000000033 (ops 158-162)
I20260812 06:18:42.458256 11964 log.cc:1079] T 627f8f6cd1de4353aa91b74e551babea P f870f8a284b54b63b7f70343529f7b9c: Deleting log segment in path: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515512185349-11613-0/minicluster-data/ts-0-root/wals/627f8f6cd1de4353aa91b74e551babea/wal-000000034 (ops 163-166)
I20260812 06:18:42.458287 11964 log.cc:1079] T 627f8f6cd1de4353aa91b74e551babea P f870f8a284b54b63b7f70343529f7b9c: Deleting log segment in path: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515512185349-11613-0/minicluster-data/ts-0-root/wals/627f8f6cd1de4353aa91b74e551babea/wal-000000035 (ops 167-171)
I20260812 06:18:42.458318 11964 log.cc:1079] T 627f8f6cd1de4353aa91b74e551babea P f870f8a284b54b63b7f70343529f7b9c: Deleting log segment in path: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515512185349-11613-0/minicluster-data/ts-0-root/wals/627f8f6cd1de4353aa91b74e551babea/wal-000000036 (ops 172-176)
I20260812 06:18:42.458346 11964 log.cc:1079] T 627f8f6cd1de4353aa91b74e551babea P f870f8a284b54b63b7f70343529f7b9c: Deleting log segment in path: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515512185349-11613-0/minicluster-data/ts-0-root/wals/627f8f6cd1de4353aa91b74e551babea/wal-000000037 (ops 177-181)
I20260812 06:18:42.458379 11964 log.cc:1079] T 627f8f6cd1de4353aa91b74e551babea P f870f8a284b54b63b7f70343529f7b9c: Deleting log segment in path: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515512185349-11613-0/minicluster-data/ts-0-root/wals/627f8f6cd1de4353aa91b74e551babea/wal-000000038 (ops 182-186)
I20260812 06:18:42.458410 11964 log.cc:1079] T 627f8f6cd1de4353aa91b74e551babea P f870f8a284b54b63b7f70343529f7b9c: Deleting log segment in path: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515512185349-11613-0/minicluster-data/ts-0-root/wals/627f8f6cd1de4353aa91b74e551babea/wal-000000039 (ops 187-191)
I20260812 06:18:42.481796 11964 maintenance_manager.cc:643] P f870f8a284b54b63b7f70343529f7b9c: LogGCOp(627f8f6cd1de4353aa91b74e551babea) complete. Timing: real 0.024s	user 0.001s	sys 0.023s Metrics: {}
I20260812 06:18:42.482223 12035 maintenance_manager.cc:419] P f870f8a284b54b63b7f70343529f7b9c: Scheduling FlushDeltaMemStoresOp(627f8f6cd1de4353aa91b74e551babea): perf score=3.181125
I20260812 06:18:42.495604 11964 maintenance_manager.cc:643] P f870f8a284b54b63b7f70343529f7b9c: FlushDeltaMemStoresOp(627f8f6cd1de4353aa91b74e551babea) complete. Timing: real 0.013s	user 0.001s	sys 0.009s Metrics: {"bytes_written":4512902,"delete_count":0,"lbm_write_time_us":4228,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:42.496114 12035 maintenance_manager.cc:419] P f870f8a284b54b63b7f70343529f7b9c: Scheduling LogGCOp(627f8f6cd1de4353aa91b74e551babea): free 12018006 bytes of WAL
I20260812 06:18:42.496321 11964 log_reader.cc:385] T 627f8f6cd1de4353aa91b74e551babea: removed 1 log segments from log reader
I20260812 06:18:42.496380 11964 log.cc:1079] T 627f8f6cd1de4353aa91b74e551babea P f870f8a284b54b63b7f70343529f7b9c: Deleting log segment in path: /tmp/dist-test-task54JXQO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515512185349-11613-0/minicluster-data/ts-0-root/wals/627f8f6cd1de4353aa91b74e551babea/wal-000000040 (ops 192-196)
I20260812 06:18:42.499045 11964 maintenance_manager.cc:643] P f870f8a284b54b63b7f70343529f7b9c: LogGCOp(627f8f6cd1de4353aa91b74e551babea) complete. Timing: real 0.003s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:18:42.499403 12035 maintenance_manager.cc:419] P f870f8a284b54b63b7f70343529f7b9c: Scheduling FlushDeltaMemStoresOp(627f8f6cd1de4353aa91b74e551babea): perf score=2.188937
I20260812 06:18:42.514008 11964 maintenance_manager.cc:643] P f870f8a284b54b63b7f70343529f7b9c: FlushDeltaMemStoresOp(627f8f6cd1de4353aa91b74e551babea) complete. Timing: real 0.014s	user 0.013s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5434,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:42.514586 12035 maintenance_manager.cc:419] P f870f8a284b54b63b7f70343529f7b9c: Scheduling UndoDeltaBlockGCOp(627f8f6cd1de4353aa91b74e551babea): 482 bytes on disk
I20260812 06:18:42.515244 11964 maintenance_manager.cc:643] P f870f8a284b54b63b7f70343529f7b9c: UndoDeltaBlockGCOp(627f8f6cd1de4353aa91b74e551babea) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":92,"lbm_reads_lt_1ms":4}
I20260812 06:18:42.515822 12035 maintenance_manager.cc:419] P f870f8a284b54b63b7f70343529f7b9c: Scheduling MajorDeltaCompactionOp(627f8f6cd1de4353aa91b74e551babea): perf score=1.000000
I20260812 06:18:42.593014 11613 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.627s	user 1.711s	sys 0.167s
I20260812 06:18:42.681357 11613 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.088s	user 0.003s	sys 0.000s
I20260812 06:18:42.681854 11613 tablet_server.cc:179] TabletServer@127.11.87.65:0 shutting down...
I20260812 06:18:42.714016 11964 maintenance_manager.cc:643] P f870f8a284b54b63b7f70343529f7b9c: MajorDeltaCompactionOp(627f8f6cd1de4353aa91b74e551babea) complete. Timing: real 0.198s	user 0.135s	sys 0.063s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020733,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":952,"lbm_read_time_us":15421,"lbm_reads_lt_1ms":766,"lbm_write_time_us":29591,"lbm_writes_lt_1ms":743,"mutex_wait_us":78,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":1920,"thread_start_us":79,"threads_started":1,"update_count":3500}
I20260812 06:18:42.715184 11613 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:42.715806 11613 tablet_replica.cc:333] T 627f8f6cd1de4353aa91b74e551babea P f870f8a284b54b63b7f70343529f7b9c: stopping tablet replica
I20260812 06:18:42.715974 11613 raft_consensus.cc:2243] T 627f8f6cd1de4353aa91b74e551babea P f870f8a284b54b63b7f70343529f7b9c [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:42.716140 11613 raft_consensus.cc:2272] T 627f8f6cd1de4353aa91b74e551babea P f870f8a284b54b63b7f70343529f7b9c [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:42.732246 11613 tablet_server.cc:196] TabletServer@127.11.87.65:0 shutdown complete.
I20260812 06:18:42.773075 11613 master.cc:562] Master@127.11.87.126:36831 shutting down...
I20260812 06:18:42.776752 11613 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 276df5aed9c245fdb34fffe959b871db [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:42.777019 11613 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 276df5aed9c245fdb34fffe959b871db [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:42.777102 11613 tablet_replica.cc:333] T 00000000000000000000000000000000 P 276df5aed9c245fdb34fffe959b871db: stopping tablet replica
I20260812 06:18:42.789939 11613 master.cc:584] Master@127.11.87.126:36831 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5104 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10663 ms total)

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