[==========] 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:16:47.467069 31521 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.30.200.126:46367
I20260812 06:16:47.468183 31521 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:16:47.468869 31521 file_cache.cc:504] Constructed file cache file cache with capacity 419430
I20260812 06:16:47.476004 31521 server_base.cc:1061] running on GCE node
W20260812 06:16:47.476087 31531 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:16:47.476198 31534 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:16:47.476416 31530 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:16:47.476969 31521 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:47.477123 31521 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:16:47.477181 31521 hybrid_clock.cc:648] HybridClock initialized: now 1786515407477178 us; error 0 us; skew 500 ppm
I20260812 06:16:47.479241 31521 webserver.cc:533] Webserver started at http://127.30.200.126:40149/ using document root <none> and password file <none>
I20260812 06:16:47.479857 31521 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:47.479956 31521 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:47.480232 31521 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:47.482111 31521 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515407455541-31521-0/minicluster-data/master-0-root/instance:
uuid: "293cf365eb4e4f1f89823cf1ed248d74"
format_stamp: "Formatted at 2026-08-12 06:16:47 on dist-test-slave-6ntk"
I20260812 06:16:47.486105 31521 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.003s	sys 0.001s
I20260812 06:16:47.488590 31543 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:16:47.489904 31521 fs_manager.cc:730] Time spent opening block manager: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:16:47.490064 31521 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515407455541-31521-0/minicluster-data/master-0-root
uuid: "293cf365eb4e4f1f89823cf1ed248d74"
format_stamp: "Formatted at 2026-08-12 06:16:47 on dist-test-slave-6ntk"
I20260812 06:16:47.490187 31521 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515407455541-31521-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515407455541-31521-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515407455541-31521-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:16:47.500233 31521 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:47.500967 31521 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:16:47.501165 31521 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:47.509796 31521 rpc_server.cc:307] RPC server started. Bound to: 127.30.200.126:46367
I20260812 06:16:47.509835 31650 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.30.200.126:46367 every 8 connection(s)
I20260812 06:16:47.512532 31652 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:16:47.518800 31652 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 293cf365eb4e4f1f89823cf1ed248d74: Bootstrap starting.
I20260812 06:16:47.521519 31652 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 293cf365eb4e4f1f89823cf1ed248d74: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:47.522580 31652 log.cc:826] T 00000000000000000000000000000000 P 293cf365eb4e4f1f89823cf1ed248d74: Log is configured to *not* fsync() on all Append() calls
I20260812 06:16:47.524530 31652 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 293cf365eb4e4f1f89823cf1ed248d74: No bootstrap required, opened a new log
I20260812 06:16:47.527752 31652 raft_consensus.cc:359] T 00000000000000000000000000000000 P 293cf365eb4e4f1f89823cf1ed248d74 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "293cf365eb4e4f1f89823cf1ed248d74" member_type: VOTER }
I20260812 06:16:47.527936 31652 raft_consensus.cc:385] T 00000000000000000000000000000000 P 293cf365eb4e4f1f89823cf1ed248d74 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:47.527980 31652 raft_consensus.cc:740] T 00000000000000000000000000000000 P 293cf365eb4e4f1f89823cf1ed248d74 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 293cf365eb4e4f1f89823cf1ed248d74, State: Initialized, Role: FOLLOWER
I20260812 06:16:47.528551 31652 consensus_queue.cc:260] T 00000000000000000000000000000000 P 293cf365eb4e4f1f89823cf1ed248d74 [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: "293cf365eb4e4f1f89823cf1ed248d74" member_type: VOTER }
I20260812 06:16:47.528692 31652 raft_consensus.cc:399] T 00000000000000000000000000000000 P 293cf365eb4e4f1f89823cf1ed248d74 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:47.528735 31652 raft_consensus.cc:493] T 00000000000000000000000000000000 P 293cf365eb4e4f1f89823cf1ed248d74 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:47.528846 31652 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 293cf365eb4e4f1f89823cf1ed248d74 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:47.529655 31652 raft_consensus.cc:515] T 00000000000000000000000000000000 P 293cf365eb4e4f1f89823cf1ed248d74 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "293cf365eb4e4f1f89823cf1ed248d74" member_type: VOTER }
I20260812 06:16:47.530175 31652 leader_election.cc:304] T 00000000000000000000000000000000 P 293cf365eb4e4f1f89823cf1ed248d74 [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: 293cf365eb4e4f1f89823cf1ed248d74; no voters: 
I20260812 06:16:47.530514 31652 leader_election.cc:290] T 00000000000000000000000000000000 P 293cf365eb4e4f1f89823cf1ed248d74 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:47.530673 31663 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 293cf365eb4e4f1f89823cf1ed248d74 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:47.530994 31663 raft_consensus.cc:697] T 00000000000000000000000000000000 P 293cf365eb4e4f1f89823cf1ed248d74 [term 1 LEADER]: Becoming Leader. State: Replica: 293cf365eb4e4f1f89823cf1ed248d74, State: Running, Role: LEADER
I20260812 06:16:47.531481 31663 consensus_queue.cc:237] T 00000000000000000000000000000000 P 293cf365eb4e4f1f89823cf1ed248d74 [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: "293cf365eb4e4f1f89823cf1ed248d74" member_type: VOTER }
I20260812 06:16:47.531668 31652 sys_catalog.cc:565] T 00000000000000000000000000000000 P 293cf365eb4e4f1f89823cf1ed248d74 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:16:47.533587 31665 sys_catalog.cc:455] T 00000000000000000000000000000000 P 293cf365eb4e4f1f89823cf1ed248d74 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 293cf365eb4e4f1f89823cf1ed248d74. Latest consensus state: current_term: 1 leader_uuid: "293cf365eb4e4f1f89823cf1ed248d74" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "293cf365eb4e4f1f89823cf1ed248d74" member_type: VOTER } }
I20260812 06:16:47.533558 31664 sys_catalog.cc:455] T 00000000000000000000000000000000 P 293cf365eb4e4f1f89823cf1ed248d74 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "293cf365eb4e4f1f89823cf1ed248d74" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "293cf365eb4e4f1f89823cf1ed248d74" member_type: VOTER } }
I20260812 06:16:47.533696 31665 sys_catalog.cc:458] T 00000000000000000000000000000000 P 293cf365eb4e4f1f89823cf1ed248d74 [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:47.533696 31664 sys_catalog.cc:458] T 00000000000000000000000000000000 P 293cf365eb4e4f1f89823cf1ed248d74 [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:47.534173 31521 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:16:47.534204 31681 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:16:47.536584 31681 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:16:47.542253 31681 catalog_manager.cc:1383] Generated new cluster ID: 137ab6bb3571495e947a4cf1c8bfe932
I20260812 06:16:47.542337 31681 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:16:47.558003 31681 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:16:47.559027 31681 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:16:47.564810 31681 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 293cf365eb4e4f1f89823cf1ed248d74: Generated new TSK 0
I20260812 06:16:47.565611 31681 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:16:47.599206 31521 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:47.602334 31697 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:16:47.602442 31691 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:16:47.602510 31695 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:16:47.602658 31521 server_base.cc:1061] running on GCE node
I20260812 06:16:47.603029 31521 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:47.603101 31521 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:16:47.603130 31521 hybrid_clock.cc:648] HybridClock initialized: now 1786515407603129 us; error 0 us; skew 500 ppm
I20260812 06:16:47.604161 31521 webserver.cc:533] Webserver started at http://127.30.200.65:37519/ using document root <none> and password file <none>
I20260812 06:16:47.604344 31521 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:47.604420 31521 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:47.604506 31521 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:47.604964 31521 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515407455541-31521-0/minicluster-data/ts-0-root/instance:
uuid: "61c894e1d82b4e7a826a52464c90af5e"
format_stamp: "Formatted at 2026-08-12 06:16:47 on dist-test-slave-6ntk"
I20260812 06:16:47.606719 31521 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:16:47.607818 31708 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:16:47.608088 31521 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:16:47.608156 31521 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515407455541-31521-0/minicluster-data/ts-0-root
uuid: "61c894e1d82b4e7a826a52464c90af5e"
format_stamp: "Formatted at 2026-08-12 06:16:47 on dist-test-slave-6ntk"
I20260812 06:16:47.608250 31521 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515407455541-31521-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515407455541-31521-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515407455541-31521-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:16:47.654170 31521 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:47.654693 31521 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:47.655283 31521 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:16:47.656337 31521 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:16:47.656395 31521 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:47.656445 31521 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:16:47.656510 31521 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:47.664567 31521 rpc_server.cc:307] RPC server started. Bound to: 127.30.200.65:46767
I20260812 06:16:47.664601 31834 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.30.200.65:46767 every 8 connection(s)
I20260812 06:16:47.677461 31836 heartbeater.cc:344] Connected to a master server at 127.30.200.126:46367
I20260812 06:16:47.677780 31836 heartbeater.cc:461] Registering TS with master...
I20260812 06:16:47.678385 31836 heartbeater.cc:507] Master 127.30.200.126:46367 requested a full tablet report, sending...
I20260812 06:16:47.680280 31569 ts_manager.cc:194] Registered new tserver with Master: 61c894e1d82b4e7a826a52464c90af5e (127.30.200.65:46767)
I20260812 06:16:47.680431 31521 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.015076471s
I20260812 06:16:47.682204 31569 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:47318
I20260812 06:16:47.691473 31569 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:47328:
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:16:47.706861 31759 tablet_service.cc:1511] Processing CreateTablet for tablet b2dc1bae3b5a4be88a67ff77618f52ce (DEFAULT_TABLE table=heavy-update-compaction-test [id=83ac17eb4738482abd04819b29f229d2]), partition=
I20260812 06:16:47.707419 31759 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet b2dc1bae3b5a4be88a67ff77618f52ce. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:16:47.710601 31857 tablet_bootstrap.cc:492] T b2dc1bae3b5a4be88a67ff77618f52ce P 61c894e1d82b4e7a826a52464c90af5e: Bootstrap starting.
I20260812 06:16:47.711638 31857 tablet_bootstrap.cc:654] T b2dc1bae3b5a4be88a67ff77618f52ce P 61c894e1d82b4e7a826a52464c90af5e: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:47.712796 31857 tablet_bootstrap.cc:492] T b2dc1bae3b5a4be88a67ff77618f52ce P 61c894e1d82b4e7a826a52464c90af5e: No bootstrap required, opened a new log
I20260812 06:16:47.712927 31857 ts_tablet_manager.cc:1403] T b2dc1bae3b5a4be88a67ff77618f52ce P 61c894e1d82b4e7a826a52464c90af5e: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:16:47.713438 31857 raft_consensus.cc:359] T b2dc1bae3b5a4be88a67ff77618f52ce P 61c894e1d82b4e7a826a52464c90af5e [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "61c894e1d82b4e7a826a52464c90af5e" member_type: VOTER last_known_addr { host: "127.30.200.65" port: 46767 } }
I20260812 06:16:47.713732 31857 raft_consensus.cc:385] T b2dc1bae3b5a4be88a67ff77618f52ce P 61c894e1d82b4e7a826a52464c90af5e [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:47.713798 31857 raft_consensus.cc:740] T b2dc1bae3b5a4be88a67ff77618f52ce P 61c894e1d82b4e7a826a52464c90af5e [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 61c894e1d82b4e7a826a52464c90af5e, State: Initialized, Role: FOLLOWER
I20260812 06:16:47.714032 31857 consensus_queue.cc:260] T b2dc1bae3b5a4be88a67ff77618f52ce P 61c894e1d82b4e7a826a52464c90af5e [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: "61c894e1d82b4e7a826a52464c90af5e" member_type: VOTER last_known_addr { host: "127.30.200.65" port: 46767 } }
I20260812 06:16:47.714170 31857 raft_consensus.cc:399] T b2dc1bae3b5a4be88a67ff77618f52ce P 61c894e1d82b4e7a826a52464c90af5e [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:47.714244 31857 raft_consensus.cc:493] T b2dc1bae3b5a4be88a67ff77618f52ce P 61c894e1d82b4e7a826a52464c90af5e [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:47.714309 31857 raft_consensus.cc:3060] T b2dc1bae3b5a4be88a67ff77618f52ce P 61c894e1d82b4e7a826a52464c90af5e [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:47.715059 31857 raft_consensus.cc:515] T b2dc1bae3b5a4be88a67ff77618f52ce P 61c894e1d82b4e7a826a52464c90af5e [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "61c894e1d82b4e7a826a52464c90af5e" member_type: VOTER last_known_addr { host: "127.30.200.65" port: 46767 } }
I20260812 06:16:47.715247 31857 leader_election.cc:304] T b2dc1bae3b5a4be88a67ff77618f52ce P 61c894e1d82b4e7a826a52464c90af5e [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: 61c894e1d82b4e7a826a52464c90af5e; no voters: 
I20260812 06:16:47.715507 31857 leader_election.cc:290] T b2dc1bae3b5a4be88a67ff77618f52ce P 61c894e1d82b4e7a826a52464c90af5e [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:47.715673 31860 raft_consensus.cc:2804] T b2dc1bae3b5a4be88a67ff77618f52ce P 61c894e1d82b4e7a826a52464c90af5e [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:47.715956 31860 raft_consensus.cc:697] T b2dc1bae3b5a4be88a67ff77618f52ce P 61c894e1d82b4e7a826a52464c90af5e [term 1 LEADER]: Becoming Leader. State: Replica: 61c894e1d82b4e7a826a52464c90af5e, State: Running, Role: LEADER
I20260812 06:16:47.716013 31857 ts_tablet_manager.cc:1434] T b2dc1bae3b5a4be88a67ff77618f52ce P 61c894e1d82b4e7a826a52464c90af5e: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:16:47.716378 31836 heartbeater.cc:499] Master 127.30.200.126:46367 was elected leader, sending a full tablet report...
I20260812 06:16:47.716840 31860 consensus_queue.cc:237] T b2dc1bae3b5a4be88a67ff77618f52ce P 61c894e1d82b4e7a826a52464c90af5e [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: "61c894e1d82b4e7a826a52464c90af5e" member_type: VOTER last_known_addr { host: "127.30.200.65" port: 46767 } }
I20260812 06:16:47.719986 31568 catalog_manager.cc:5719] T b2dc1bae3b5a4be88a67ff77618f52ce P 61c894e1d82b4e7a826a52464c90af5e reported cstate change: term changed from 0 to 1, leader changed from <none> to 61c894e1d82b4e7a826a52464c90af5e (127.30.200.65). New cstate: current_term: 1 leader_uuid: "61c894e1d82b4e7a826a52464c90af5e" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "61c894e1d82b4e7a826a52464c90af5e" member_type: VOTER last_known_addr { host: "127.30.200.65" port: 46767 } health_report { overall_health: HEALTHY } } }
I20260812 06:16:47.788566 31521 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.060s	user 0.016s	sys 0.012s
I20260812 06:16:47.915931 31837 maintenance_manager.cc:419] P 61c894e1d82b4e7a826a52464c90af5e: Scheduling FlushMRSOp(b2dc1bae3b5a4be88a67ff77618f52ce): perf score=15.086190
I20260812 06:16:48.088076 31717 maintenance_manager.cc:643] P 61c894e1d82b4e7a826a52464c90af5e: FlushMRSOp(b2dc1bae3b5a4be88a67ff77618f52ce) complete. Timing: real 0.172s	user 0.121s	sys 0.048s Metrics: {"bytes_written":12635684,"cfile_init":1,"compiler_manager_pool.queue_time_us":251,"delete_count":0,"dirs.queue_time_us":1062,"dirs.run_cpu_time_us":213,"dirs.run_wall_time_us":1577,"drs_written":1,"lbm_read_time_us":77,"lbm_reads_lt_1ms":4,"lbm_write_time_us":41787,"lbm_writes_lt_1ms":665,"peak_mem_usage":0,"reinsert_count":0,"rows_written":103,"spinlock_wait_cycles":188288,"thread_start_us":166,"threads_started":1,"update_count":1540}
I20260812 06:16:48.089325 31837 maintenance_manager.cc:419] P 61c894e1d82b4e7a826a52464c90af5e: Scheduling LogGCOp(b2dc1bae3b5a4be88a67ff77618f52ce): free 8725963 bytes of WAL
I20260812 06:16:48.089644 31717 log_reader.cc:385] T b2dc1bae3b5a4be88a67ff77618f52ce: removed 1 log segments from log reader
I20260812 06:16:48.089706 31717 log.cc:1079] T b2dc1bae3b5a4be88a67ff77618f52ce P 61c894e1d82b4e7a826a52464c90af5e: Deleting log segment in path: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515407455541-31521-0/minicluster-data/ts-0-root/wals/b2dc1bae3b5a4be88a67ff77618f52ce/wal-000000001 (ops 1-6)
I20260812 06:16:48.092285 31717 maintenance_manager.cc:643] P 61c894e1d82b4e7a826a52464c90af5e: LogGCOp(b2dc1bae3b5a4be88a67ff77618f52ce) complete. Timing: real 0.003s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:16:48.092687 31837 maintenance_manager.cc:419] P 61c894e1d82b4e7a826a52464c90af5e: Scheduling UndoDeltaBlockGCOp(b2dc1bae3b5a4be88a67ff77618f52ce): 12308957 bytes on disk
I20260812 06:16:48.093367 31717 maintenance_manager.cc:643] P 61c894e1d82b4e7a826a52464c90af5e: UndoDeltaBlockGCOp(b2dc1bae3b5a4be88a67ff77618f52ce) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":66,"lbm_reads_lt_1ms":4}
I20260812 06:16:48.093834 31837 maintenance_manager.cc:419] P 61c894e1d82b4e7a826a52464c90af5e: Scheduling FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce): perf score=2.188937
I20260812 06:16:48.108765 31717 maintenance_manager.cc:643] P 61c894e1d82b4e7a826a52464c90af5e: FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102663,"delete_count":0,"lbm_write_time_us":5765,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:48.109283 31837 maintenance_manager.cc:419] P 61c894e1d82b4e7a826a52464c90af5e: Scheduling FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce): perf score=2.188937
I20260812 06:16:48.119549 31717 maintenance_manager.cc:643] P 61c894e1d82b4e7a826a52464c90af5e: FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3774458,"delete_count":0,"lbm_write_time_us":3696,"lbm_writes_lt_1ms":95,"reinsert_count":0,"update_count":460}
I20260812 06:16:48.120092 31837 maintenance_manager.cc:419] P 61c894e1d82b4e7a826a52464c90af5e: Scheduling MajorDeltaCompactionOp(b2dc1bae3b5a4be88a67ff77618f52ce): perf score=1.000000
I20260812 06:16:48.310321 31717 maintenance_manager.cc:643] P 61c894e1d82b4e7a826a52464c90af5e: MajorDeltaCompactionOp(b2dc1bae3b5a4be88a67ff77618f52ce) complete. Timing: real 0.190s	user 0.133s	sys 0.049s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24733840,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":684,"lbm_read_time_us":11186,"lbm_reads_lt_1ms":569,"lbm_write_time_us":37438,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":379,"threads_started":5,"update_count":2500}
I20260812 06:16:48.310914 31837 maintenance_manager.cc:419] P 61c894e1d82b4e7a826a52464c90af5e: Scheduling FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce): perf score=10.126437
I20260812 06:16:48.362030 31717 maintenance_manager.cc:643] P 61c894e1d82b4e7a826a52464c90af5e: FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce) complete. Timing: real 0.051s	user 0.025s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":20682,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:48.362586 31837 maintenance_manager.cc:419] P 61c894e1d82b4e7a826a52464c90af5e: Scheduling FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce): perf score=2.188937
I20260812 06:16:48.374452 31717 maintenance_manager.cc:643] P 61c894e1d82b4e7a826a52464c90af5e: FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4324,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:48.374964 31837 maintenance_manager.cc:419] P 61c894e1d82b4e7a826a52464c90af5e: Scheduling MajorDeltaCompactionOp(b2dc1bae3b5a4be88a67ff77618f52ce): perf score=1.000000
I20260812 06:16:48.505571 31717 maintenance_manager.cc:643] P 61c894e1d82b4e7a826a52464c90af5e: MajorDeltaCompactionOp(b2dc1bae3b5a4be88a67ff77618f52ce) complete. Timing: real 0.130s	user 0.106s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":261,"lbm_read_time_us":9194,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26785,"lbm_writes_lt_1ms":443,"mutex_wait_us":20,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9984,"update_count":2000}
I20260812 06:16:48.506230 31837 maintenance_manager.cc:419] P 61c894e1d82b4e7a826a52464c90af5e: Scheduling FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce): perf score=10.126437
I20260812 06:16:48.549542 31717 maintenance_manager.cc:643] P 61c894e1d82b4e7a826a52464c90af5e: FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce) complete. Timing: real 0.043s	user 0.025s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19022,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:48.550216 31837 maintenance_manager.cc:419] P 61c894e1d82b4e7a826a52464c90af5e: Scheduling FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce): perf score=2.188937
I20260812 06:16:48.564024 31717 maintenance_manager.cc:643] P 61c894e1d82b4e7a826a52464c90af5e: FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce) complete. Timing: real 0.014s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5059,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:48.564725 31837 maintenance_manager.cc:419] P 61c894e1d82b4e7a826a52464c90af5e: Scheduling MajorDeltaCompactionOp(b2dc1bae3b5a4be88a67ff77618f52ce): perf score=1.000000
I20260812 06:16:48.713594 31717 maintenance_manager.cc:643] P 61c894e1d82b4e7a826a52464c90af5e: MajorDeltaCompactionOp(b2dc1bae3b5a4be88a67ff77618f52ce) complete. Timing: real 0.149s	user 0.123s	sys 0.025s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":236,"lbm_read_time_us":10743,"lbm_reads_lt_1ms":464,"lbm_write_time_us":30252,"lbm_writes_lt_1ms":443,"mutex_wait_us":41,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":16896,"update_count":2000}
I20260812 06:16:48.714310 31837 maintenance_manager.cc:419] P 61c894e1d82b4e7a826a52464c90af5e: Scheduling FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce): perf score=10.126437
I20260812 06:16:48.768276 31717 maintenance_manager.cc:643] P 61c894e1d82b4e7a826a52464c90af5e: FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce) complete. Timing: real 0.054s	user 0.027s	sys 0.023s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":19119,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:48.768950 31837 maintenance_manager.cc:419] P 61c894e1d82b4e7a826a52464c90af5e: Scheduling FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce): perf score=2.188937
I20260812 06:16:48.781244 31717 maintenance_manager.cc:643] P 61c894e1d82b4e7a826a52464c90af5e: FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4738,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:48.781862 31837 maintenance_manager.cc:419] P 61c894e1d82b4e7a826a52464c90af5e: Scheduling MajorDeltaCompactionOp(b2dc1bae3b5a4be88a67ff77618f52ce): perf score=1.000000
I20260812 06:16:48.948195 31717 maintenance_manager.cc:643] P 61c894e1d82b4e7a826a52464c90af5e: MajorDeltaCompactionOp(b2dc1bae3b5a4be88a67ff77618f52ce) complete. Timing: real 0.166s	user 0.132s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":148,"lbm_read_time_us":12617,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28331,"lbm_writes_lt_1ms":443,"mutex_wait_us":43,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":2000}
I20260812 06:16:48.952210 31837 maintenance_manager.cc:419] P 61c894e1d82b4e7a826a52464c90af5e: Scheduling FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce): perf score=10.126437
I20260812 06:16:49.000494 31717 maintenance_manager.cc:643] P 61c894e1d82b4e7a826a52464c90af5e: FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce) complete. Timing: real 0.048s	user 0.015s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16307,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:49.001070 31837 maintenance_manager.cc:419] P 61c894e1d82b4e7a826a52464c90af5e: Scheduling FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce): perf score=2.188937
I20260812 06:16:49.012771 31717 maintenance_manager.cc:643] P 61c894e1d82b4e7a826a52464c90af5e: FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4488,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:49.013448 31837 maintenance_manager.cc:419] P 61c894e1d82b4e7a826a52464c90af5e: Scheduling MajorDeltaCompactionOp(b2dc1bae3b5a4be88a67ff77618f52ce): perf score=1.000000
I20260812 06:16:49.156073 31717 maintenance_manager.cc:643] P 61c894e1d82b4e7a826a52464c90af5e: MajorDeltaCompactionOp(b2dc1bae3b5a4be88a67ff77618f52ce) complete. Timing: real 0.142s	user 0.118s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":172,"lbm_read_time_us":8785,"lbm_reads_lt_1ms":472,"lbm_write_time_us":29562,"lbm_writes_lt_1ms":443,"mutex_wait_us":38,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":14720,"update_count":2000}
I20260812 06:16:49.156898 31837 maintenance_manager.cc:419] P 61c894e1d82b4e7a826a52464c90af5e: Scheduling FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce): perf score=10.126437
I20260812 06:16:49.203435 31717 maintenance_manager.cc:643] P 61c894e1d82b4e7a826a52464c90af5e: FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce) complete. Timing: real 0.046s	user 0.024s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15966,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:49.203974 31837 maintenance_manager.cc:419] P 61c894e1d82b4e7a826a52464c90af5e: Scheduling FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce): perf score=2.188937
I20260812 06:16:49.216035 31717 maintenance_manager.cc:643] P 61c894e1d82b4e7a826a52464c90af5e: FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4243,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:49.216830 31837 maintenance_manager.cc:419] P 61c894e1d82b4e7a826a52464c90af5e: Scheduling MajorDeltaCompactionOp(b2dc1bae3b5a4be88a67ff77618f52ce): perf score=1.000000
I20260812 06:16:49.378120 31717 maintenance_manager.cc:643] P 61c894e1d82b4e7a826a52464c90af5e: MajorDeltaCompactionOp(b2dc1bae3b5a4be88a67ff77618f52ce) complete. Timing: real 0.161s	user 0.116s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":5342,"lbm_read_time_us":10581,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28239,"lbm_writes_lt_1ms":443,"mutex_wait_us":4965,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2560,"update_count":2000}
I20260812 06:16:49.378803 31837 maintenance_manager.cc:419] P 61c894e1d82b4e7a826a52464c90af5e: Scheduling FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce): perf score=10.126437
I20260812 06:16:49.429847 31717 maintenance_manager.cc:643] P 61c894e1d82b4e7a826a52464c90af5e: FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce) complete. Timing: real 0.051s	user 0.029s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19552,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:49.430467 31837 maintenance_manager.cc:419] P 61c894e1d82b4e7a826a52464c90af5e: Scheduling FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce): perf score=2.188937
I20260812 06:16:49.446274 31717 maintenance_manager.cc:643] P 61c894e1d82b4e7a826a52464c90af5e: FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce) complete. Timing: real 0.016s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5841,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:49.447111 31837 maintenance_manager.cc:419] P 61c894e1d82b4e7a826a52464c90af5e: Scheduling FlushMRSOp(b2dc1bae3b5a4be88a67ff77618f52ce): perf score=1.000000
I20260812 06:16:49.486541 31717 maintenance_manager.cc:643] P 61c894e1d82b4e7a826a52464c90af5e: FlushMRSOp(b2dc1bae3b5a4be88a67ff77618f52ce) complete. Timing: real 0.039s	user 0.035s	sys 0.000s Metrics: {"bytes_written":1193504,"cfile_init":1,"dirs.queue_time_us":82,"dirs.run_cpu_time_us":242,"dirs.run_wall_time_us":1399,"drs_written":1,"lbm_read_time_us":66,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2201,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:16:49.487489 31837 maintenance_manager.cc:419] P 61c894e1d82b4e7a826a52464c90af5e: Scheduling LogGCOp(b2dc1bae3b5a4be88a67ff77618f52ce): free 124257241 bytes of WAL
I20260812 06:16:49.487720 31717 log_reader.cc:385] T b2dc1bae3b5a4be88a67ff77618f52ce: removed 12 log segments from log reader
I20260812 06:16:49.487769 31717 log.cc:1079] T b2dc1bae3b5a4be88a67ff77618f52ce P 61c894e1d82b4e7a826a52464c90af5e: Deleting log segment in path: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515407455541-31521-0/minicluster-data/ts-0-root/wals/b2dc1bae3b5a4be88a67ff77618f52ce/wal-000000002 (ops 7-11)
I20260812 06:16:49.487810 31717 log.cc:1079] T b2dc1bae3b5a4be88a67ff77618f52ce P 61c894e1d82b4e7a826a52464c90af5e: Deleting log segment in path: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515407455541-31521-0/minicluster-data/ts-0-root/wals/b2dc1bae3b5a4be88a67ff77618f52ce/wal-000000003 (ops 12-16)
I20260812 06:16:49.487847 31717 log.cc:1079] T b2dc1bae3b5a4be88a67ff77618f52ce P 61c894e1d82b4e7a826a52464c90af5e: Deleting log segment in path: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515407455541-31521-0/minicluster-data/ts-0-root/wals/b2dc1bae3b5a4be88a67ff77618f52ce/wal-000000004 (ops 17-21)
I20260812 06:16:49.487877 31717 log.cc:1079] T b2dc1bae3b5a4be88a67ff77618f52ce P 61c894e1d82b4e7a826a52464c90af5e: Deleting log segment in path: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515407455541-31521-0/minicluster-data/ts-0-root/wals/b2dc1bae3b5a4be88a67ff77618f52ce/wal-000000005 (ops 22-26)
I20260812 06:16:49.487905 31717 log.cc:1079] T b2dc1bae3b5a4be88a67ff77618f52ce P 61c894e1d82b4e7a826a52464c90af5e: Deleting log segment in path: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515407455541-31521-0/minicluster-data/ts-0-root/wals/b2dc1bae3b5a4be88a67ff77618f52ce/wal-000000006 (ops 27-31)
I20260812 06:16:49.487932 31717 log.cc:1079] T b2dc1bae3b5a4be88a67ff77618f52ce P 61c894e1d82b4e7a826a52464c90af5e: Deleting log segment in path: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515407455541-31521-0/minicluster-data/ts-0-root/wals/b2dc1bae3b5a4be88a67ff77618f52ce/wal-000000007 (ops 32-36)
I20260812 06:16:49.487959 31717 log.cc:1079] T b2dc1bae3b5a4be88a67ff77618f52ce P 61c894e1d82b4e7a826a52464c90af5e: Deleting log segment in path: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515407455541-31521-0/minicluster-data/ts-0-root/wals/b2dc1bae3b5a4be88a67ff77618f52ce/wal-000000008 (ops 37-40)
I20260812 06:16:49.487991 31717 log.cc:1079] T b2dc1bae3b5a4be88a67ff77618f52ce P 61c894e1d82b4e7a826a52464c90af5e: Deleting log segment in path: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515407455541-31521-0/minicluster-data/ts-0-root/wals/b2dc1bae3b5a4be88a67ff77618f52ce/wal-000000009 (ops 41-45)
I20260812 06:16:49.488021 31717 log.cc:1079] T b2dc1bae3b5a4be88a67ff77618f52ce P 61c894e1d82b4e7a826a52464c90af5e: Deleting log segment in path: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515407455541-31521-0/minicluster-data/ts-0-root/wals/b2dc1bae3b5a4be88a67ff77618f52ce/wal-000000010 (ops 46-50)
I20260812 06:16:49.488049 31717 log.cc:1079] T b2dc1bae3b5a4be88a67ff77618f52ce P 61c894e1d82b4e7a826a52464c90af5e: Deleting log segment in path: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515407455541-31521-0/minicluster-data/ts-0-root/wals/b2dc1bae3b5a4be88a67ff77618f52ce/wal-000000011 (ops 51-55)
I20260812 06:16:49.488075 31717 log.cc:1079] T b2dc1bae3b5a4be88a67ff77618f52ce P 61c894e1d82b4e7a826a52464c90af5e: Deleting log segment in path: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515407455541-31521-0/minicluster-data/ts-0-root/wals/b2dc1bae3b5a4be88a67ff77618f52ce/wal-000000012 (ops 56-60)
I20260812 06:16:49.488101 31717 log.cc:1079] T b2dc1bae3b5a4be88a67ff77618f52ce P 61c894e1d82b4e7a826a52464c90af5e: Deleting log segment in path: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515407455541-31521-0/minicluster-data/ts-0-root/wals/b2dc1bae3b5a4be88a67ff77618f52ce/wal-000000013 (ops 61-65)
I20260812 06:16:49.523569 31717 maintenance_manager.cc:643] P 61c894e1d82b4e7a826a52464c90af5e: LogGCOp(b2dc1bae3b5a4be88a67ff77618f52ce) complete. Timing: real 0.036s	user 0.003s	sys 0.031s Metrics: {}
I20260812 06:16:49.524091 31837 maintenance_manager.cc:419] P 61c894e1d82b4e7a826a52464c90af5e: Scheduling FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce): perf score=2.188937
I20260812 06:16:49.550770 31717 maintenance_manager.cc:643] P 61c894e1d82b4e7a826a52464c90af5e: FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce) complete. Timing: real 0.026s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5215,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:49.551342 31837 maintenance_manager.cc:419] P 61c894e1d82b4e7a826a52464c90af5e: Scheduling FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce): perf score=2.188937
I20260812 06:16:49.563238 31717 maintenance_manager.cc:643] P 61c894e1d82b4e7a826a52464c90af5e: FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce) complete. Timing: real 0.012s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4543,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:49.563771 31837 maintenance_manager.cc:419] P 61c894e1d82b4e7a826a52464c90af5e: Scheduling UndoDeltaBlockGCOp(b2dc1bae3b5a4be88a67ff77618f52ce): 462 bytes on disk
I20260812 06:16:49.564210 31717 maintenance_manager.cc:643] P 61c894e1d82b4e7a826a52464c90af5e: UndoDeltaBlockGCOp(b2dc1bae3b5a4be88a67ff77618f52ce) 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:16:49.564657 31837 maintenance_manager.cc:419] P 61c894e1d82b4e7a826a52464c90af5e: Scheduling MajorDeltaCompactionOp(b2dc1bae3b5a4be88a67ff77618f52ce): perf score=1.000000
I20260812 06:16:49.751120 31717 maintenance_manager.cc:643] P 61c894e1d82b4e7a826a52464c90af5e: MajorDeltaCompactionOp(b2dc1bae3b5a4be88a67ff77618f52ce) complete. Timing: real 0.186s	user 0.132s	sys 0.040s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836374,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":455,"lbm_read_time_us":12735,"lbm_reads_lt_1ms":674,"lbm_write_time_us":32805,"lbm_writes_lt_1ms":643,"mutex_wait_us":39,"peak_mem_usage":75542472,"reinsert_count":0,"thread_start_us":79,"threads_started":1,"update_count":3000}
I20260812 06:16:49.751879 31837 maintenance_manager.cc:419] P 61c894e1d82b4e7a826a52464c90af5e: Scheduling FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce): perf score=10.126437
I20260812 06:16:49.804206 31717 maintenance_manager.cc:643] P 61c894e1d82b4e7a826a52464c90af5e: FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce) complete. Timing: real 0.051s	user 0.032s	sys 0.003s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":16420,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:49.804742 31837 maintenance_manager.cc:419] P 61c894e1d82b4e7a826a52464c90af5e: Scheduling FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce): perf score=2.188937
I20260812 06:16:49.817699 31717 maintenance_manager.cc:643] P 61c894e1d82b4e7a826a52464c90af5e: FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce) complete. Timing: real 0.013s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4494,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:49.818332 31837 maintenance_manager.cc:419] P 61c894e1d82b4e7a826a52464c90af5e: Scheduling MajorDeltaCompactionOp(b2dc1bae3b5a4be88a67ff77618f52ce): perf score=1.000000
I20260812 06:16:49.947767 31717 maintenance_manager.cc:643] P 61c894e1d82b4e7a826a52464c90af5e: MajorDeltaCompactionOp(b2dc1bae3b5a4be88a67ff77618f52ce) complete. Timing: real 0.129s	user 0.096s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631313,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1378,"lbm_read_time_us":9375,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26584,"lbm_writes_lt_1ms":443,"mutex_wait_us":432,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":24832,"update_count":2000}
I20260812 06:16:49.948487 31837 maintenance_manager.cc:419] P 61c894e1d82b4e7a826a52464c90af5e: Scheduling FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce): perf score=10.126437
I20260812 06:16:50.003317 31717 maintenance_manager.cc:643] P 61c894e1d82b4e7a826a52464c90af5e: FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce) complete. Timing: real 0.055s	user 0.029s	sys 0.013s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19319,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:16:50.003960 31837 maintenance_manager.cc:419] P 61c894e1d82b4e7a826a52464c90af5e: Scheduling FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce): perf score=2.188937
I20260812 06:16:50.021132 31717 maintenance_manager.cc:643] P 61c894e1d82b4e7a826a52464c90af5e: FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce) complete. Timing: real 0.017s	user 0.011s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6430,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:50.021940 31837 maintenance_manager.cc:419] P 61c894e1d82b4e7a826a52464c90af5e: Scheduling MajorDeltaCompactionOp(b2dc1bae3b5a4be88a67ff77618f52ce): perf score=1.000000
I20260812 06:16:50.185906 31717 maintenance_manager.cc:643] P 61c894e1d82b4e7a826a52464c90af5e: MajorDeltaCompactionOp(b2dc1bae3b5a4be88a67ff77618f52ce) complete. Timing: real 0.164s	user 0.087s	sys 0.076s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":711,"lbm_read_time_us":13185,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27910,"lbm_writes_lt_1ms":443,"mutex_wait_us":342,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3840,"update_count":2000}
I20260812 06:16:50.186559 31837 maintenance_manager.cc:419] P 61c894e1d82b4e7a826a52464c90af5e: Scheduling FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce): perf score=10.126437
I20260812 06:16:50.233026 31717 maintenance_manager.cc:643] P 61c894e1d82b4e7a826a52464c90af5e: FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce) complete. Timing: real 0.046s	user 0.031s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16679,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:50.233632 31837 maintenance_manager.cc:419] P 61c894e1d82b4e7a826a52464c90af5e: Scheduling FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce): perf score=2.188937
I20260812 06:16:50.245918 31717 maintenance_manager.cc:643] P 61c894e1d82b4e7a826a52464c90af5e: FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce) complete. Timing: real 0.012s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4471,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:50.246726 31837 maintenance_manager.cc:419] P 61c894e1d82b4e7a826a52464c90af5e: Scheduling MajorDeltaCompactionOp(b2dc1bae3b5a4be88a67ff77618f52ce): perf score=1.000000
I20260812 06:16:50.378903 31717 maintenance_manager.cc:643] P 61c894e1d82b4e7a826a52464c90af5e: MajorDeltaCompactionOp(b2dc1bae3b5a4be88a67ff77618f52ce) complete. Timing: real 0.132s	user 0.100s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":373,"lbm_read_time_us":10807,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26553,"lbm_writes_lt_1ms":443,"mutex_wait_us":38,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:16:50.379525 31837 maintenance_manager.cc:419] P 61c894e1d82b4e7a826a52464c90af5e: Scheduling FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce): perf score=10.126437
I20260812 06:16:50.424772 31717 maintenance_manager.cc:643] P 61c894e1d82b4e7a826a52464c90af5e: FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce) complete. Timing: real 0.045s	user 0.038s	sys 0.004s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":20788,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:16:50.425271 31837 maintenance_manager.cc:419] P 61c894e1d82b4e7a826a52464c90af5e: Scheduling FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce): perf score=2.188937
I20260812 06:16:50.437407 31717 maintenance_manager.cc:643] P 61c894e1d82b4e7a826a52464c90af5e: FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce) complete. Timing: real 0.012s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4308,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:50.437947 31837 maintenance_manager.cc:419] P 61c894e1d82b4e7a826a52464c90af5e: Scheduling MajorDeltaCompactionOp(b2dc1bae3b5a4be88a67ff77618f52ce): perf score=1.000000
I20260812 06:16:50.576418 31717 maintenance_manager.cc:643] P 61c894e1d82b4e7a826a52464c90af5e: MajorDeltaCompactionOp(b2dc1bae3b5a4be88a67ff77618f52ce) complete. Timing: real 0.138s	user 0.109s	sys 0.029s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631311,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":181,"lbm_read_time_us":9341,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26418,"lbm_writes_lt_1ms":443,"mutex_wait_us":45,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11648,"update_count":2000}
I20260812 06:16:50.577036 31837 maintenance_manager.cc:419] P 61c894e1d82b4e7a826a52464c90af5e: Scheduling FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce): perf score=10.126437
I20260812 06:16:50.624208 31717 maintenance_manager.cc:643] P 61c894e1d82b4e7a826a52464c90af5e: FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce) complete. Timing: real 0.047s	user 0.029s	sys 0.016s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":19849,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:16:50.624883 31837 maintenance_manager.cc:419] P 61c894e1d82b4e7a826a52464c90af5e: Scheduling FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce): perf score=2.188937
I20260812 06:16:50.646302 31717 maintenance_manager.cc:643] P 61c894e1d82b4e7a826a52464c90af5e: FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce) complete. Timing: real 0.021s	user 0.016s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6335,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:50.646832 31837 maintenance_manager.cc:419] P 61c894e1d82b4e7a826a52464c90af5e: Scheduling MajorDeltaCompactionOp(b2dc1bae3b5a4be88a67ff77618f52ce): perf score=1.000000
I20260812 06:16:50.772980 31717 maintenance_manager.cc:643] P 61c894e1d82b4e7a826a52464c90af5e: MajorDeltaCompactionOp(b2dc1bae3b5a4be88a67ff77618f52ce) complete. Timing: real 0.126s	user 0.107s	sys 0.016s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631310,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":147,"lbm_read_time_us":10072,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24188,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2000}
I20260812 06:16:50.773782 31837 maintenance_manager.cc:419] P 61c894e1d82b4e7a826a52464c90af5e: Scheduling FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce): perf score=10.126437
I20260812 06:16:50.820047 31717 maintenance_manager.cc:643] P 61c894e1d82b4e7a826a52464c90af5e: FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce) complete. Timing: real 0.046s	user 0.008s	sys 0.035s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":18197,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:16:50.820816 31837 maintenance_manager.cc:419] P 61c894e1d82b4e7a826a52464c90af5e: Scheduling FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce): perf score=2.188937
I20260812 06:16:50.834203 31717 maintenance_manager.cc:643] P 61c894e1d82b4e7a826a52464c90af5e: FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce) complete. Timing: real 0.013s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4749,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:50.834865 31837 maintenance_manager.cc:419] P 61c894e1d82b4e7a826a52464c90af5e: Scheduling MajorDeltaCompactionOp(b2dc1bae3b5a4be88a67ff77618f52ce): perf score=1.000000
I20260812 06:16:50.995692 31717 maintenance_manager.cc:643] P 61c894e1d82b4e7a826a52464c90af5e: MajorDeltaCompactionOp(b2dc1bae3b5a4be88a67ff77618f52ce) complete. Timing: real 0.161s	user 0.099s	sys 0.056s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631314,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1308,"lbm_read_time_us":9765,"lbm_reads_lt_1ms":468,"lbm_write_time_us":25783,"lbm_writes_lt_1ms":443,"mutex_wait_us":536,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10368,"update_count":2000}
I20260812 06:16:50.996417 31837 maintenance_manager.cc:419] P 61c894e1d82b4e7a826a52464c90af5e: Scheduling FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce): perf score=11.118625
I20260812 06:16:51.038134 31717 maintenance_manager.cc:643] P 61c894e1d82b4e7a826a52464c90af5e: FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce) complete. Timing: real 0.041s	user 0.018s	sys 0.023s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":18119,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":311,"reinsert_count":0,"update_count":1550}
I20260812 06:16:51.038777 31837 maintenance_manager.cc:419] P 61c894e1d82b4e7a826a52464c90af5e: Scheduling FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce): perf score=2.188937
I20260812 06:16:51.050127 31717 maintenance_manager.cc:643] P 61c894e1d82b4e7a826a52464c90af5e: FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4150,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:51.050613 31837 maintenance_manager.cc:419] P 61c894e1d82b4e7a826a52464c90af5e: Scheduling FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce): perf score=2.188937
I20260812 06:16:51.060288 31717 maintenance_manager.cc:643] P 61c894e1d82b4e7a826a52464c90af5e: FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce) complete. Timing: real 0.009s	user 0.000s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3574,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:51.060814 31837 maintenance_manager.cc:419] P 61c894e1d82b4e7a826a52464c90af5e: Scheduling FlushMRSOp(b2dc1bae3b5a4be88a67ff77618f52ce): perf score=1.000000
I20260812 06:16:51.102542 31717 maintenance_manager.cc:643] P 61c894e1d82b4e7a826a52464c90af5e: FlushMRSOp(b2dc1bae3b5a4be88a67ff77618f52ce) complete. Timing: real 0.042s	user 0.036s	sys 0.000s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":56,"dirs.run_cpu_time_us":265,"dirs.run_wall_time_us":1369,"drs_written":1,"lbm_read_time_us":86,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2049,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:16:51.103525 31837 maintenance_manager.cc:419] P 61c894e1d82b4e7a826a52464c90af5e: Scheduling LogGCOp(b2dc1bae3b5a4be88a67ff77618f52ce): free 128414394 bytes of WAL
I20260812 06:16:51.103860 31717 log_reader.cc:385] T b2dc1bae3b5a4be88a67ff77618f52ce: removed 13 log segments from log reader
I20260812 06:16:51.103928 31717 log.cc:1079] T b2dc1bae3b5a4be88a67ff77618f52ce P 61c894e1d82b4e7a826a52464c90af5e: Deleting log segment in path: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515407455541-31521-0/minicluster-data/ts-0-root/wals/b2dc1bae3b5a4be88a67ff77618f52ce/wal-000000014 (ops 66-70)
I20260812 06:16:51.103972 31717 log.cc:1079] T b2dc1bae3b5a4be88a67ff77618f52ce P 61c894e1d82b4e7a826a52464c90af5e: Deleting log segment in path: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515407455541-31521-0/minicluster-data/ts-0-root/wals/b2dc1bae3b5a4be88a67ff77618f52ce/wal-000000015 (ops 71-75)
I20260812 06:16:51.104007 31717 log.cc:1079] T b2dc1bae3b5a4be88a67ff77618f52ce P 61c894e1d82b4e7a826a52464c90af5e: Deleting log segment in path: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515407455541-31521-0/minicluster-data/ts-0-root/wals/b2dc1bae3b5a4be88a67ff77618f52ce/wal-000000016 (ops 76-80)
I20260812 06:16:51.104035 31717 log.cc:1079] T b2dc1bae3b5a4be88a67ff77618f52ce P 61c894e1d82b4e7a826a52464c90af5e: Deleting log segment in path: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515407455541-31521-0/minicluster-data/ts-0-root/wals/b2dc1bae3b5a4be88a67ff77618f52ce/wal-000000017 (ops 81-84)
I20260812 06:16:51.104063 31717 log.cc:1079] T b2dc1bae3b5a4be88a67ff77618f52ce P 61c894e1d82b4e7a826a52464c90af5e: Deleting log segment in path: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515407455541-31521-0/minicluster-data/ts-0-root/wals/b2dc1bae3b5a4be88a67ff77618f52ce/wal-000000018 (ops 85-89)
I20260812 06:16:51.104095 31717 log.cc:1079] T b2dc1bae3b5a4be88a67ff77618f52ce P 61c894e1d82b4e7a826a52464c90af5e: Deleting log segment in path: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515407455541-31521-0/minicluster-data/ts-0-root/wals/b2dc1bae3b5a4be88a67ff77618f52ce/wal-000000019 (ops 90-94)
I20260812 06:16:51.104118 31717 log.cc:1079] T b2dc1bae3b5a4be88a67ff77618f52ce P 61c894e1d82b4e7a826a52464c90af5e: Deleting log segment in path: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515407455541-31521-0/minicluster-data/ts-0-root/wals/b2dc1bae3b5a4be88a67ff77618f52ce/wal-000000020 (ops 95-98)
I20260812 06:16:51.104144 31717 log.cc:1079] T b2dc1bae3b5a4be88a67ff77618f52ce P 61c894e1d82b4e7a826a52464c90af5e: Deleting log segment in path: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515407455541-31521-0/minicluster-data/ts-0-root/wals/b2dc1bae3b5a4be88a67ff77618f52ce/wal-000000021 (ops 99-103)
I20260812 06:16:51.104178 31717 log.cc:1079] T b2dc1bae3b5a4be88a67ff77618f52ce P 61c894e1d82b4e7a826a52464c90af5e: Deleting log segment in path: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515407455541-31521-0/minicluster-data/ts-0-root/wals/b2dc1bae3b5a4be88a67ff77618f52ce/wal-000000022 (ops 104-108)
I20260812 06:16:51.104208 31717 log.cc:1079] T b2dc1bae3b5a4be88a67ff77618f52ce P 61c894e1d82b4e7a826a52464c90af5e: Deleting log segment in path: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515407455541-31521-0/minicluster-data/ts-0-root/wals/b2dc1bae3b5a4be88a67ff77618f52ce/wal-000000023 (ops 109-112)
I20260812 06:16:51.104238 31717 log.cc:1079] T b2dc1bae3b5a4be88a67ff77618f52ce P 61c894e1d82b4e7a826a52464c90af5e: Deleting log segment in path: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515407455541-31521-0/minicluster-data/ts-0-root/wals/b2dc1bae3b5a4be88a67ff77618f52ce/wal-000000024 (ops 113-117)
I20260812 06:16:51.104269 31717 log.cc:1079] T b2dc1bae3b5a4be88a67ff77618f52ce P 61c894e1d82b4e7a826a52464c90af5e: Deleting log segment in path: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515407455541-31521-0/minicluster-data/ts-0-root/wals/b2dc1bae3b5a4be88a67ff77618f52ce/wal-000000025 (ops 118-122)
I20260812 06:16:51.104301 31717 log.cc:1079] T b2dc1bae3b5a4be88a67ff77618f52ce P 61c894e1d82b4e7a826a52464c90af5e: Deleting log segment in path: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515407455541-31521-0/minicluster-data/ts-0-root/wals/b2dc1bae3b5a4be88a67ff77618f52ce/wal-000000026 (ops 123-126)
I20260812 06:16:51.137458 31717 maintenance_manager.cc:643] P 61c894e1d82b4e7a826a52464c90af5e: LogGCOp(b2dc1bae3b5a4be88a67ff77618f52ce) complete. Timing: real 0.034s	user 0.000s	sys 0.030s Metrics: {}
I20260812 06:16:51.138077 31837 maintenance_manager.cc:419] P 61c894e1d82b4e7a826a52464c90af5e: Scheduling FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce): perf score=3.181125
I20260812 06:16:51.163528 31717 maintenance_manager.cc:643] P 61c894e1d82b4e7a826a52464c90af5e: FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce) complete. Timing: real 0.025s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4756,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:16:51.164105 31837 maintenance_manager.cc:419] P 61c894e1d82b4e7a826a52464c90af5e: Scheduling FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce): perf score=2.188937
I20260812 06:16:51.174486 31717 maintenance_manager.cc:643] P 61c894e1d82b4e7a826a52464c90af5e: FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce) complete. Timing: real 0.010s	user 0.002s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3800,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:51.175052 31837 maintenance_manager.cc:419] P 61c894e1d82b4e7a826a52464c90af5e: Scheduling MajorDeltaCompactionOp(b2dc1bae3b5a4be88a67ff77618f52ce): perf score=1.000000
I20260812 06:16:51.402776 31717 maintenance_manager.cc:643] P 61c894e1d82b4e7a826a52464c90af5e: MajorDeltaCompactionOp(b2dc1bae3b5a4be88a67ff77618f52ce) complete. Timing: real 0.228s	user 0.156s	sys 0.071s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32938887,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":1158,"lbm_read_time_us":13879,"lbm_reads_lt_1ms":775,"lbm_write_time_us":40881,"lbm_writes_lt_1ms":743,"mutex_wait_us":356,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":1280,"thread_start_us":114,"threads_started":1,"update_count":3500}
I20260812 06:16:51.405156 31837 maintenance_manager.cc:419] P 61c894e1d82b4e7a826a52464c90af5e: Scheduling FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce): perf score=14.095187
I20260812 06:16:51.467425 31717 maintenance_manager.cc:643] P 61c894e1d82b4e7a826a52464c90af5e: FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce) complete. Timing: real 0.062s	user 0.025s	sys 0.027s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":23928,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:51.468006 31837 maintenance_manager.cc:419] P 61c894e1d82b4e7a826a52464c90af5e: Scheduling UndoDeltaBlockGCOp(b2dc1bae3b5a4be88a67ff77618f52ce): 483 bytes on disk
I20260812 06:16:51.468487 31717 maintenance_manager.cc:643] P 61c894e1d82b4e7a826a52464c90af5e: UndoDeltaBlockGCOp(b2dc1bae3b5a4be88a67ff77618f52ce) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":67,"lbm_reads_lt_1ms":4}
I20260812 06:16:51.469018 31837 maintenance_manager.cc:419] P 61c894e1d82b4e7a826a52464c90af5e: Scheduling FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce): perf score=2.188937
I20260812 06:16:51.481053 31717 maintenance_manager.cc:643] P 61c894e1d82b4e7a826a52464c90af5e: FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce) complete. Timing: real 0.012s	user 0.003s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4653,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:51.481678 31837 maintenance_manager.cc:419] P 61c894e1d82b4e7a826a52464c90af5e: Scheduling MajorDeltaCompactionOp(b2dc1bae3b5a4be88a67ff77618f52ce): perf score=1.000000
I20260812 06:16:51.691046 31717 maintenance_manager.cc:643] P 61c894e1d82b4e7a826a52464c90af5e: MajorDeltaCompactionOp(b2dc1bae3b5a4be88a67ff77618f52ce) complete. Timing: real 0.209s	user 0.128s	sys 0.072s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733722,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":343,"lbm_read_time_us":14339,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34772,"lbm_writes_lt_1ms":543,"mutex_wait_us":60,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13312,"update_count":2500}
I20260812 06:16:51.692121 31837 maintenance_manager.cc:419] P 61c894e1d82b4e7a826a52464c90af5e: Scheduling FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce): perf score=14.095187
I20260812 06:16:51.819295 31717 maintenance_manager.cc:643] P 61c894e1d82b4e7a826a52464c90af5e: FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce) complete. Timing: real 0.127s	user 0.037s	sys 0.008s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":18805,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:51.820013 31837 maintenance_manager.cc:419] P 61c894e1d82b4e7a826a52464c90af5e: Scheduling FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce): perf score=6.157687
I20260812 06:16:51.913893 31717 maintenance_manager.cc:643] P 61c894e1d82b4e7a826a52464c90af5e: FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce) complete. Timing: real 0.094s	user 0.019s	sys 0.006s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":11492,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:16:51.914729 31837 maintenance_manager.cc:419] P 61c894e1d82b4e7a826a52464c90af5e: Scheduling FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce): perf score=6.157687
I20260812 06:16:52.019914 31717 maintenance_manager.cc:643] P 61c894e1d82b4e7a826a52464c90af5e: FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce) complete. Timing: real 0.105s	user 0.020s	sys 0.004s Metrics: {"bytes_written":8205077,"delete_count":0,"lbm_write_time_us":10585,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:16:52.020748 31837 maintenance_manager.cc:419] P 61c894e1d82b4e7a826a52464c90af5e: Scheduling FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce): perf score=8.142062
I20260812 06:16:52.128407 31717 maintenance_manager.cc:643] P 61c894e1d82b4e7a826a52464c90af5e: FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce) complete. Timing: real 0.107s	user 0.019s	sys 0.004s Metrics: {"bytes_written":10133212,"delete_count":0,"lbm_write_time_us":10472,"lbm_writes_lt_1ms":250,"reinsert_count":0,"update_count":1235}
I20260812 06:16:52.129021 31837 maintenance_manager.cc:419] P 61c894e1d82b4e7a826a52464c90af5e: Scheduling FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce): perf score=9.134250
I20260812 06:16:52.230000 31717 maintenance_manager.cc:643] P 61c894e1d82b4e7a826a52464c90af5e: FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce) complete. Timing: real 0.101s	user 0.021s	sys 0.015s Metrics: {"bytes_written":10379352,"delete_count":0,"lbm_write_time_us":14180,"lbm_writes_lt_1ms":256,"reinsert_count":0,"update_count":1265}
I20260812 06:16:52.231484 31837 maintenance_manager.cc:419] P 61c894e1d82b4e7a826a52464c90af5e: Scheduling FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce): perf score=6.157687
I20260812 06:16:52.335244 31717 maintenance_manager.cc:643] P 61c894e1d82b4e7a826a52464c90af5e: FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce) complete. Timing: real 0.104s	user 0.010s	sys 0.008s Metrics: {"bytes_written":7384594,"delete_count":0,"lbm_write_time_us":7743,"lbm_writes_lt_1ms":183,"reinsert_count":0,"update_count":900}
I20260812 06:16:52.335855 31837 maintenance_manager.cc:419] P 61c894e1d82b4e7a826a52464c90af5e: Scheduling FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce): perf score=7.149875
I20260812 06:16:52.437806 31717 maintenance_manager.cc:643] P 61c894e1d82b4e7a826a52464c90af5e: FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce) complete. Timing: real 0.102s	user 0.025s	sys 0.004s Metrics: {"bytes_written":9025560,"delete_count":0,"lbm_write_time_us":12881,"lbm_writes_lt_1ms":223,"reinsert_count":0,"update_count":1100}
I20260812 06:16:52.438692 31837 maintenance_manager.cc:419] P 61c894e1d82b4e7a826a52464c90af5e: Scheduling FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce): perf score=6.157687
I20260812 06:16:52.542481 31717 maintenance_manager.cc:643] P 61c894e1d82b4e7a826a52464c90af5e: FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce) complete. Timing: real 0.103s	user 0.024s	sys 0.004s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":11600,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:16:52.543430 31837 maintenance_manager.cc:419] P 61c894e1d82b4e7a826a52464c90af5e: Scheduling FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce): perf score=7.149875
I20260812 06:16:52.647143 31717 maintenance_manager.cc:643] P 61c894e1d82b4e7a826a52464c90af5e: FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce) complete. Timing: real 0.103s	user 0.009s	sys 0.013s Metrics: {"bytes_written":8615324,"delete_count":0,"lbm_write_time_us":8510,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:16:52.647921 31837 maintenance_manager.cc:419] P 61c894e1d82b4e7a826a52464c90af5e: Scheduling FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce): perf score=7.149875
I20260812 06:16:52.758956 31717 maintenance_manager.cc:643] P 61c894e1d82b4e7a826a52464c90af5e: FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce) complete. Timing: real 0.111s	user 0.013s	sys 0.015s Metrics: {"bytes_written":8656347,"delete_count":0,"lbm_write_time_us":10068,"lbm_writes_lt_1ms":214,"reinsert_count":0,"update_count":1055}
I20260812 06:16:52.759745 31837 maintenance_manager.cc:419] P 61c894e1d82b4e7a826a52464c90af5e: Scheduling FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce): perf score=10.126437
I20260812 06:16:52.852458 31717 maintenance_manager.cc:643] P 61c894e1d82b4e7a826a52464c90af5e: FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce) complete. Timing: real 0.092s	user 0.021s	sys 0.010s Metrics: {"bytes_written":11445994,"delete_count":0,"lbm_write_time_us":14167,"lbm_writes_lt_1ms":282,"reinsert_count":0,"update_count":1395}
I20260812 06:16:52.853456 31837 maintenance_manager.cc:419] P 61c894e1d82b4e7a826a52464c90af5e: Scheduling FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce): perf score=3.181125
I20260812 06:16:52.950708 31717 maintenance_manager.cc:643] P 61c894e1d82b4e7a826a52464c90af5e: FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce) complete. Timing: real 0.097s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4933,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:16:52.951354 31837 maintenance_manager.cc:419] P 61c894e1d82b4e7a826a52464c90af5e: Scheduling FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce): perf score=6.157687
I20260812 06:16:52.967952 31521 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.179s	user 1.867s	sys 0.138s
I20260812 06:16:53.054998 31717 maintenance_manager.cc:643] P 61c894e1d82b4e7a826a52464c90af5e: FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce) complete. Timing: real 0.103s	user 0.013s	sys 0.012s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":11011,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:16:53.055740 31837 maintenance_manager.cc:419] P 61c894e1d82b4e7a826a52464c90af5e: Scheduling FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce): perf score=2.188937
I20260812 06:16:53.153694 31717 maintenance_manager.cc:643] P 61c894e1d82b4e7a826a52464c90af5e: FlushDeltaMemStoresOp(b2dc1bae3b5a4be88a67ff77618f52ce) complete. Timing: real 0.098s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3749,"lbm_writes_lt_1ms":93,"reinsert_count":0,"spinlock_wait_cycles":2816,"update_count":450}
I20260812 06:16:53.154381 31837 maintenance_manager.cc:419] P 61c894e1d82b4e7a826a52464c90af5e: Scheduling FlushMRSOp(b2dc1bae3b5a4be88a67ff77618f52ce): perf score=1.000000
I20260812 06:16:53.258665 31717 maintenance_manager.cc:643] P 61c894e1d82b4e7a826a52464c90af5e: FlushMRSOp(b2dc1bae3b5a4be88a67ff77618f52ce) complete. Timing: real 0.104s	user 0.027s	sys 0.003s Metrics: {"bytes_written":1521477,"cfile_init":1,"dirs.queue_time_us":247,"dirs.run_cpu_time_us":342,"dirs.run_wall_time_us":77204,"drs_written":1,"lbm_read_time_us":77,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1922,"lbm_writes_lt_1ms":44,"peak_mem_usage":0,"rows_written":37,"spinlock_wait_cycles":1408,"thread_start_us":131,"threads_started":1}
I20260812 06:16:53.259498 31837 maintenance_manager.cc:419] P 61c894e1d82b4e7a826a52464c90af5e: Scheduling LogGCOp(b2dc1bae3b5a4be88a67ff77618f52ce): free 142244861 bytes of WAL
I20260812 06:16:53.259778 31717 log_reader.cc:385] T b2dc1bae3b5a4be88a67ff77618f52ce: removed 14 log segments from log reader
I20260812 06:16:53.259848 31717 log.cc:1079] T b2dc1bae3b5a4be88a67ff77618f52ce P 61c894e1d82b4e7a826a52464c90af5e: Deleting log segment in path: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515407455541-31521-0/minicluster-data/ts-0-root/wals/b2dc1bae3b5a4be88a67ff77618f52ce/wal-000000027 (ops 127-131)
I20260812 06:16:53.259934 31717 log.cc:1079] T b2dc1bae3b5a4be88a67ff77618f52ce P 61c894e1d82b4e7a826a52464c90af5e: Deleting log segment in path: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515407455541-31521-0/minicluster-data/ts-0-root/wals/b2dc1bae3b5a4be88a67ff77618f52ce/wal-000000028 (ops 132-136)
I20260812 06:16:53.260003 31717 log.cc:1079] T b2dc1bae3b5a4be88a67ff77618f52ce P 61c894e1d82b4e7a826a52464c90af5e: Deleting log segment in path: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515407455541-31521-0/minicluster-data/ts-0-root/wals/b2dc1bae3b5a4be88a67ff77618f52ce/wal-000000029 (ops 137-141)
I20260812 06:16:53.260083 31717 log.cc:1079] T b2dc1bae3b5a4be88a67ff77618f52ce P 61c894e1d82b4e7a826a52464c90af5e: Deleting log segment in path: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515407455541-31521-0/minicluster-data/ts-0-root/wals/b2dc1bae3b5a4be88a67ff77618f52ce/wal-000000030 (ops 142-146)
I20260812 06:16:53.260150 31717 log.cc:1079] T b2dc1bae3b5a4be88a67ff77618f52ce P 61c894e1d82b4e7a826a52464c90af5e: Deleting log segment in path: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515407455541-31521-0/minicluster-data/ts-0-root/wals/b2dc1bae3b5a4be88a67ff77618f52ce/wal-000000031 (ops 147-151)
I20260812 06:16:53.260211 31717 log.cc:1079] T b2dc1bae3b5a4be88a67ff77618f52ce P 61c894e1d82b4e7a826a52464c90af5e: Deleting log segment in path: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515407455541-31521-0/minicluster-data/ts-0-root/wals/b2dc1bae3b5a4be88a67ff77618f52ce/wal-000000032 (ops 152-156)
I20260812 06:16:53.260251 31717 log.cc:1079] T b2dc1bae3b5a4be88a67ff77618f52ce P 61c894e1d82b4e7a826a52464c90af5e: Deleting log segment in path: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515407455541-31521-0/minicluster-data/ts-0-root/wals/b2dc1bae3b5a4be88a67ff77618f52ce/wal-000000033 (ops 157-161)
I20260812 06:16:53.260337 31717 log.cc:1079] T b2dc1bae3b5a4be88a67ff77618f52ce P 61c894e1d82b4e7a826a52464c90af5e: Deleting log segment in path: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515407455541-31521-0/minicluster-data/ts-0-root/wals/b2dc1bae3b5a4be88a67ff77618f52ce/wal-000000034 (ops 162-166)
I20260812 06:16:53.260378 31717 log.cc:1079] T b2dc1bae3b5a4be88a67ff77618f52ce P 61c894e1d82b4e7a826a52464c90af5e: Deleting log segment in path: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515407455541-31521-0/minicluster-data/ts-0-root/wals/b2dc1bae3b5a4be88a67ff77618f52ce/wal-000000035 (ops 167-171)
I20260812 06:16:53.260449 31717 log.cc:1079] T b2dc1bae3b5a4be88a67ff77618f52ce P 61c894e1d82b4e7a826a52464c90af5e: Deleting log segment in path: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515407455541-31521-0/minicluster-data/ts-0-root/wals/b2dc1bae3b5a4be88a67ff77618f52ce/wal-000000036 (ops 172-176)
I20260812 06:16:53.260490 31717 log.cc:1079] T b2dc1bae3b5a4be88a67ff77618f52ce P 61c894e1d82b4e7a826a52464c90af5e: Deleting log segment in path: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515407455541-31521-0/minicluster-data/ts-0-root/wals/b2dc1bae3b5a4be88a67ff77618f52ce/wal-000000037 (ops 177-181)
I20260812 06:16:53.260561 31717 log.cc:1079] T b2dc1bae3b5a4be88a67ff77618f52ce P 61c894e1d82b4e7a826a52464c90af5e: Deleting log segment in path: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515407455541-31521-0/minicluster-data/ts-0-root/wals/b2dc1bae3b5a4be88a67ff77618f52ce/wal-000000038 (ops 182-186)
I20260812 06:16:53.260602 31717 log.cc:1079] T b2dc1bae3b5a4be88a67ff77618f52ce P 61c894e1d82b4e7a826a52464c90af5e: Deleting log segment in path: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515407455541-31521-0/minicluster-data/ts-0-root/wals/b2dc1bae3b5a4be88a67ff77618f52ce/wal-000000039 (ops 187-191)
I20260812 06:16:53.260890 31717 log.cc:1079] T b2dc1bae3b5a4be88a67ff77618f52ce P 61c894e1d82b4e7a826a52464c90af5e: Deleting log segment in path: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515407455541-31521-0/minicluster-data/ts-0-root/wals/b2dc1bae3b5a4be88a67ff77618f52ce/wal-000000040 (ops 192-196)
I20260812 06:16:53.288053 31521 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.320s	user 0.002s	sys 0.000s
I20260812 06:16:53.288796 31521 tablet_server.cc:179] TabletServer@127.30.200.65:0 shutting down...
I20260812 06:16:53.291894 31717 maintenance_manager.cc:643] P 61c894e1d82b4e7a826a52464c90af5e: LogGCOp(b2dc1bae3b5a4be88a67ff77618f52ce) complete. Timing: real 0.032s	user 0.000s	sys 0.030s Metrics: {}
I20260812 06:16:53.292567 31837 maintenance_manager.cc:419] P 61c894e1d82b4e7a826a52464c90af5e: Scheduling LogGCOp(b2dc1bae3b5a4be88a67ff77618f52ce): free 12017949 bytes of WAL
I20260812 06:16:53.292923 31717 log_reader.cc:385] T b2dc1bae3b5a4be88a67ff77618f52ce: removed 1 log segments from log reader
I20260812 06:16:53.293009 31717 log.cc:1079] T b2dc1bae3b5a4be88a67ff77618f52ce P 61c894e1d82b4e7a826a52464c90af5e: Deleting log segment in path: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515407455541-31521-0/minicluster-data/ts-0-root/wals/b2dc1bae3b5a4be88a67ff77618f52ce/wal-000000041 (ops 197-201)
I20260812 06:16:53.296419 31717 maintenance_manager.cc:643] P 61c894e1d82b4e7a826a52464c90af5e: LogGCOp(b2dc1bae3b5a4be88a67ff77618f52ce) complete. Timing: real 0.004s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:16:53.296965 31521 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:16:53.298009 31521 tablet_replica.cc:333] T b2dc1bae3b5a4be88a67ff77618f52ce P 61c894e1d82b4e7a826a52464c90af5e: stopping tablet replica
I20260812 06:16:53.298312 31521 raft_consensus.cc:2243] T b2dc1bae3b5a4be88a67ff77618f52ce P 61c894e1d82b4e7a826a52464c90af5e [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:53.298576 31521 raft_consensus.cc:2272] T b2dc1bae3b5a4be88a67ff77618f52ce P 61c894e1d82b4e7a826a52464c90af5e [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:53.315454 31521 tablet_server.cc:196] TabletServer@127.30.200.65:0 shutdown complete.
I20260812 06:16:53.321002 31521 master.cc:562] Master@127.30.200.126:46367 shutting down...
I20260812 06:16:53.325753 31521 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 293cf365eb4e4f1f89823cf1ed248d74 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:53.326117 31521 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 293cf365eb4e4f1f89823cf1ed248d74 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:53.326227 31521 tablet_replica.cc:333] T 00000000000000000000000000000000 P 293cf365eb4e4f1f89823cf1ed248d74: stopping tablet replica
I20260812 06:16:53.339286 31521 master.cc:584] Master@127.30.200.126:46367 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5970 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:16:53.454928 31521 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.30.200.126:38439
I20260812 06:16:53.455432 31521 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:53.458477 31887 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:16:53.458846 31521 server_base.cc:1061] running on GCE node
W20260812 06:16:53.458564 31889 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:16:53.459022 31891 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:16:53.459280 31521 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:53.459332 31521 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:16:53.459355 31521 hybrid_clock.cc:648] HybridClock initialized: now 1786515413459355 us; error 0 us; skew 500 ppm
I20260812 06:16:53.460397 31521 webserver.cc:533] Webserver started at http://127.30.200.126:45007/ using document root <none> and password file <none>
I20260812 06:16:53.460572 31521 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:53.460628 31521 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:53.460728 31521 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:53.461160 31521 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515407455541-31521-0/minicluster-data/master-0-root/instance:
uuid: "c4bb42fa541844c4a3d97b3a0b47a429"
format_stamp: "Formatted at 2026-08-12 06:16:53 on dist-test-slave-6ntk"
I20260812 06:16:53.463081 31521 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:16:53.465624 31909 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:16:53.466008 31521 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:16:53.466127 31521 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515407455541-31521-0/minicluster-data/master-0-root
uuid: "c4bb42fa541844c4a3d97b3a0b47a429"
format_stamp: "Formatted at 2026-08-12 06:16:53 on dist-test-slave-6ntk"
I20260812 06:16:53.466317 31521 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515407455541-31521-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515407455541-31521-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515407455541-31521-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:16:53.475059 31521 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:53.475549 31521 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:53.480559 31521 rpc_server.cc:307] RPC server started. Bound to: 127.30.200.126:38439
I20260812 06:16:53.481990 32000 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.30.200.126:38439 every 8 connection(s)
I20260812 06:16:53.483003 32003 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:16:53.496248 32003 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P c4bb42fa541844c4a3d97b3a0b47a429: Bootstrap starting.
I20260812 06:16:53.497283 32003 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P c4bb42fa541844c4a3d97b3a0b47a429: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:53.498646 32003 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P c4bb42fa541844c4a3d97b3a0b47a429: No bootstrap required, opened a new log
I20260812 06:16:53.499075 32003 raft_consensus.cc:359] T 00000000000000000000000000000000 P c4bb42fa541844c4a3d97b3a0b47a429 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c4bb42fa541844c4a3d97b3a0b47a429" member_type: VOTER }
I20260812 06:16:53.499176 32003 raft_consensus.cc:385] T 00000000000000000000000000000000 P c4bb42fa541844c4a3d97b3a0b47a429 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:53.499198 32003 raft_consensus.cc:740] T 00000000000000000000000000000000 P c4bb42fa541844c4a3d97b3a0b47a429 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: c4bb42fa541844c4a3d97b3a0b47a429, State: Initialized, Role: FOLLOWER
I20260812 06:16:53.499328 32003 consensus_queue.cc:260] T 00000000000000000000000000000000 P c4bb42fa541844c4a3d97b3a0b47a429 [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: "c4bb42fa541844c4a3d97b3a0b47a429" member_type: VOTER }
I20260812 06:16:53.499390 32003 raft_consensus.cc:399] T 00000000000000000000000000000000 P c4bb42fa541844c4a3d97b3a0b47a429 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:53.499413 32003 raft_consensus.cc:493] T 00000000000000000000000000000000 P c4bb42fa541844c4a3d97b3a0b47a429 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:53.499501 32003 raft_consensus.cc:3060] T 00000000000000000000000000000000 P c4bb42fa541844c4a3d97b3a0b47a429 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:53.558526 32003 raft_consensus.cc:515] T 00000000000000000000000000000000 P c4bb42fa541844c4a3d97b3a0b47a429 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c4bb42fa541844c4a3d97b3a0b47a429" member_type: VOTER }
I20260812 06:16:53.558828 32003 leader_election.cc:304] T 00000000000000000000000000000000 P c4bb42fa541844c4a3d97b3a0b47a429 [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: c4bb42fa541844c4a3d97b3a0b47a429; no voters: 
I20260812 06:16:53.559170 32003 leader_election.cc:290] T 00000000000000000000000000000000 P c4bb42fa541844c4a3d97b3a0b47a429 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:53.559433 32016 raft_consensus.cc:2804] T 00000000000000000000000000000000 P c4bb42fa541844c4a3d97b3a0b47a429 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:53.559780 32016 raft_consensus.cc:697] T 00000000000000000000000000000000 P c4bb42fa541844c4a3d97b3a0b47a429 [term 1 LEADER]: Becoming Leader. State: Replica: c4bb42fa541844c4a3d97b3a0b47a429, State: Running, Role: LEADER
I20260812 06:16:53.559947 32003 sys_catalog.cc:565] T 00000000000000000000000000000000 P c4bb42fa541844c4a3d97b3a0b47a429 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:16:53.560040 32016 consensus_queue.cc:237] T 00000000000000000000000000000000 P c4bb42fa541844c4a3d97b3a0b47a429 [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: "c4bb42fa541844c4a3d97b3a0b47a429" member_type: VOTER }
I20260812 06:16:53.560973 32019 sys_catalog.cc:455] T 00000000000000000000000000000000 P c4bb42fa541844c4a3d97b3a0b47a429 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "c4bb42fa541844c4a3d97b3a0b47a429" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c4bb42fa541844c4a3d97b3a0b47a429" member_type: VOTER } }
I20260812 06:16:53.561034 32020 sys_catalog.cc:455] T 00000000000000000000000000000000 P c4bb42fa541844c4a3d97b3a0b47a429 [sys.catalog]: SysCatalogTable state changed. Reason: New leader c4bb42fa541844c4a3d97b3a0b47a429. Latest consensus state: current_term: 1 leader_uuid: "c4bb42fa541844c4a3d97b3a0b47a429" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c4bb42fa541844c4a3d97b3a0b47a429" member_type: VOTER } }
I20260812 06:16:53.561095 32019 sys_catalog.cc:458] T 00000000000000000000000000000000 P c4bb42fa541844c4a3d97b3a0b47a429 [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:53.561134 32020 sys_catalog.cc:458] T 00000000000000000000000000000000 P c4bb42fa541844c4a3d97b3a0b47a429 [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:53.562124 32029 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:16:53.563247 32029 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:16:53.563513 31521 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:16:53.565626 32029 catalog_manager.cc:1383] Generated new cluster ID: b120c0eee51240ac86c90d0a578f4225
I20260812 06:16:53.565701 32029 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:16:53.575892 32029 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:16:53.576491 32029 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:16:53.583142 32029 catalog_manager.cc:6092] T 00000000000000000000000000000000 P c4bb42fa541844c4a3d97b3a0b47a429: Generated new TSK 0
I20260812 06:16:53.583328 32029 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:16:53.596153 31521 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:53.598603 32048 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:16:53.598763 32049 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:16:53.598819 32054 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:16:53.598994 31521 server_base.cc:1061] running on GCE node
I20260812 06:16:53.599189 31521 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:53.599238 31521 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:16:53.599303 31521 hybrid_clock.cc:648] HybridClock initialized: now 1786515413599303 us; error 0 us; skew 500 ppm
I20260812 06:16:53.600286 31521 webserver.cc:533] Webserver started at http://127.30.200.65:43975/ using document root <none> and password file <none>
I20260812 06:16:53.600500 31521 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:53.600571 31521 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:53.600661 31521 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:53.601136 31521 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515407455541-31521-0/minicluster-data/ts-0-root/instance:
uuid: "a885aee58dfe45f2a943e6a846077a98"
format_stamp: "Formatted at 2026-08-12 06:16:53 on dist-test-slave-6ntk"
I20260812 06:16:53.603010 31521 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:16:53.604112 32059 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:16:53.604409 31521 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:16:53.604509 31521 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515407455541-31521-0/minicluster-data/ts-0-root
uuid: "a885aee58dfe45f2a943e6a846077a98"
format_stamp: "Formatted at 2026-08-12 06:16:53 on dist-test-slave-6ntk"
I20260812 06:16:53.604605 31521 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515407455541-31521-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515407455541-31521-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515407455541-31521-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:16:53.614092 31521 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:53.614559 31521 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:53.614897 31521 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:16:53.615456 31521 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:16:53.615530 31521 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:53.615582 31521 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:16:53.615634 31521 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:53.620540 31521 rpc_server.cc:307] RPC server started. Bound to: 127.30.200.65:37053
I20260812 06:16:53.620571 32168 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.30.200.65:37053 every 8 connection(s)
I20260812 06:16:53.630179 32169 heartbeater.cc:344] Connected to a master server at 127.30.200.126:38439
I20260812 06:16:53.630348 32169 heartbeater.cc:461] Registering TS with master...
I20260812 06:16:53.630640 32169 heartbeater.cc:507] Master 127.30.200.126:38439 requested a full tablet report, sending...
I20260812 06:16:53.631475 31941 ts_manager.cc:194] Registered new tserver with Master: a885aee58dfe45f2a943e6a846077a98 (127.30.200.65:37053)
I20260812 06:16:53.632328 31521 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.011309274s
I20260812 06:16:53.632332 31941 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:47492
I20260812 06:16:53.641363 31941 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:47498:
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:16:53.652765 32101 tablet_service.cc:1511] Processing CreateTablet for tablet 6482c0062489402e9bd0a263e9265934 (DEFAULT_TABLE table=heavy-update-compaction-test [id=0e24758f83d847918ebe77181dde69a0]), partition=
I20260812 06:16:53.653167 32101 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 6482c0062489402e9bd0a263e9265934. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:16:53.655412 32187 tablet_bootstrap.cc:492] T 6482c0062489402e9bd0a263e9265934 P a885aee58dfe45f2a943e6a846077a98: Bootstrap starting.
I20260812 06:16:53.656350 32187 tablet_bootstrap.cc:654] T 6482c0062489402e9bd0a263e9265934 P a885aee58dfe45f2a943e6a846077a98: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:53.658061 32187 tablet_bootstrap.cc:492] T 6482c0062489402e9bd0a263e9265934 P a885aee58dfe45f2a943e6a846077a98: No bootstrap required, opened a new log
I20260812 06:16:53.658138 32187 ts_tablet_manager.cc:1403] T 6482c0062489402e9bd0a263e9265934 P a885aee58dfe45f2a943e6a846077a98: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:16:53.658610 32187 raft_consensus.cc:359] T 6482c0062489402e9bd0a263e9265934 P a885aee58dfe45f2a943e6a846077a98 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a885aee58dfe45f2a943e6a846077a98" member_type: VOTER last_known_addr { host: "127.30.200.65" port: 37053 } }
I20260812 06:16:53.658705 32187 raft_consensus.cc:385] T 6482c0062489402e9bd0a263e9265934 P a885aee58dfe45f2a943e6a846077a98 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:53.658727 32187 raft_consensus.cc:740] T 6482c0062489402e9bd0a263e9265934 P a885aee58dfe45f2a943e6a846077a98 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: a885aee58dfe45f2a943e6a846077a98, State: Initialized, Role: FOLLOWER
I20260812 06:16:53.658915 32187 consensus_queue.cc:260] T 6482c0062489402e9bd0a263e9265934 P a885aee58dfe45f2a943e6a846077a98 [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: "a885aee58dfe45f2a943e6a846077a98" member_type: VOTER last_known_addr { host: "127.30.200.65" port: 37053 } }
I20260812 06:16:53.659011 32187 raft_consensus.cc:399] T 6482c0062489402e9bd0a263e9265934 P a885aee58dfe45f2a943e6a846077a98 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:53.659071 32187 raft_consensus.cc:493] T 6482c0062489402e9bd0a263e9265934 P a885aee58dfe45f2a943e6a846077a98 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:53.659132 32187 raft_consensus.cc:3060] T 6482c0062489402e9bd0a263e9265934 P a885aee58dfe45f2a943e6a846077a98 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:53.660073 32187 raft_consensus.cc:515] T 6482c0062489402e9bd0a263e9265934 P a885aee58dfe45f2a943e6a846077a98 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a885aee58dfe45f2a943e6a846077a98" member_type: VOTER last_known_addr { host: "127.30.200.65" port: 37053 } }
I20260812 06:16:53.660240 32187 leader_election.cc:304] T 6482c0062489402e9bd0a263e9265934 P a885aee58dfe45f2a943e6a846077a98 [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: a885aee58dfe45f2a943e6a846077a98; no voters: 
I20260812 06:16:53.660531 32187 leader_election.cc:290] T 6482c0062489402e9bd0a263e9265934 P a885aee58dfe45f2a943e6a846077a98 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:53.660842 32194 raft_consensus.cc:2804] T 6482c0062489402e9bd0a263e9265934 P a885aee58dfe45f2a943e6a846077a98 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:53.661136 32194 raft_consensus.cc:697] T 6482c0062489402e9bd0a263e9265934 P a885aee58dfe45f2a943e6a846077a98 [term 1 LEADER]: Becoming Leader. State: Replica: a885aee58dfe45f2a943e6a846077a98, State: Running, Role: LEADER
I20260812 06:16:53.661368 32169 heartbeater.cc:499] Master 127.30.200.126:38439 was elected leader, sending a full tablet report...
I20260812 06:16:53.660926 32187 ts_tablet_manager.cc:1434] T 6482c0062489402e9bd0a263e9265934 P a885aee58dfe45f2a943e6a846077a98: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:16:53.661384 32194 consensus_queue.cc:237] T 6482c0062489402e9bd0a263e9265934 P a885aee58dfe45f2a943e6a846077a98 [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: "a885aee58dfe45f2a943e6a846077a98" member_type: VOTER last_known_addr { host: "127.30.200.65" port: 37053 } }
I20260812 06:16:53.663079 31941 catalog_manager.cc:5719] T 6482c0062489402e9bd0a263e9265934 P a885aee58dfe45f2a943e6a846077a98 reported cstate change: term changed from 0 to 1, leader changed from <none> to a885aee58dfe45f2a943e6a846077a98 (127.30.200.65). New cstate: current_term: 1 leader_uuid: "a885aee58dfe45f2a943e6a846077a98" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a885aee58dfe45f2a943e6a846077a98" member_type: VOTER last_known_addr { host: "127.30.200.65" port: 37053 } health_report { overall_health: HEALTHY } } }
I20260812 06:16:53.725497 31521 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.057s	user 0.013s	sys 0.010s
I20260812 06:16:53.871699 32174 maintenance_manager.cc:419] P a885aee58dfe45f2a943e6a846077a98: Scheduling FlushMRSOp(6482c0062489402e9bd0a263e9265934): perf score=15.086190
I20260812 06:16:54.031729 32065 maintenance_manager.cc:643] P a885aee58dfe45f2a943e6a846077a98: FlushMRSOp(6482c0062489402e9bd0a263e9265934) complete. Timing: real 0.160s	user 0.100s	sys 0.054s Metrics: {"bytes_written":11897250,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":64,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":38049,"lbm_writes_lt_1ms":657,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1450}
I20260812 06:16:54.032567 32174 maintenance_manager.cc:419] P a885aee58dfe45f2a943e6a846077a98: Scheduling LogGCOp(6482c0062489402e9bd0a263e9265934): free 20743880 bytes of WAL
I20260812 06:16:54.032867 32065 log_reader.cc:385] T 6482c0062489402e9bd0a263e9265934: removed 2 log segments from log reader
I20260812 06:16:54.032948 32065 log.cc:1079] T 6482c0062489402e9bd0a263e9265934 P a885aee58dfe45f2a943e6a846077a98: Deleting log segment in path: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515407455541-31521-0/minicluster-data/ts-0-root/wals/6482c0062489402e9bd0a263e9265934/wal-000000001 (ops 1-6)
I20260812 06:16:54.033006 32065 log.cc:1079] T 6482c0062489402e9bd0a263e9265934 P a885aee58dfe45f2a943e6a846077a98: Deleting log segment in path: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515407455541-31521-0/minicluster-data/ts-0-root/wals/6482c0062489402e9bd0a263e9265934/wal-000000002 (ops 7-11)
I20260812 06:16:54.037668 32065 maintenance_manager.cc:643] P a885aee58dfe45f2a943e6a846077a98: LogGCOp(6482c0062489402e9bd0a263e9265934) complete. Timing: real 0.005s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:16:54.038127 32174 maintenance_manager.cc:419] P a885aee58dfe45f2a943e6a846077a98: Scheduling UndoDeltaBlockGCOp(6482c0062489402e9bd0a263e9265934): 12719220 bytes on disk
I20260812 06:16:54.038628 32065 maintenance_manager.cc:643] P a885aee58dfe45f2a943e6a846077a98: UndoDeltaBlockGCOp(6482c0062489402e9bd0a263e9265934) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":63,"lbm_reads_lt_1ms":4}
I20260812 06:16:54.039219 32174 maintenance_manager.cc:419] P a885aee58dfe45f2a943e6a846077a98: Scheduling FlushDeltaMemStoresOp(6482c0062489402e9bd0a263e9265934): perf score=2.188937
I20260812 06:16:54.052904 32065 maintenance_manager.cc:643] P a885aee58dfe45f2a943e6a846077a98: FlushDeltaMemStoresOp(6482c0062489402e9bd0a263e9265934) complete. Timing: real 0.013s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5437,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:54.053483 32174 maintenance_manager.cc:419] P a885aee58dfe45f2a943e6a846077a98: Scheduling MajorDeltaCompactionOp(6482c0062489402e9bd0a263e9265934): perf score=1.000000
I20260812 06:16:54.214136 32065 maintenance_manager.cc:643] P a885aee58dfe45f2a943e6a846077a98: MajorDeltaCompactionOp(6482c0062489402e9bd0a263e9265934) complete. Timing: real 0.160s	user 0.120s	sys 0.040s Metrics: {"cfile_cache_miss":422,"cfile_cache_miss_bytes":20262037,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":658,"lbm_read_time_us":12061,"lbm_reads_lt_1ms":454,"lbm_write_time_us":28991,"lbm_writes_lt_1ms":433,"peak_mem_usage":49238594,"reinsert_count":0,"spinlock_wait_cycles":11392,"thread_start_us":423,"threads_started":5,"update_count":1950}
I20260812 06:16:54.214826 32174 maintenance_manager.cc:419] P a885aee58dfe45f2a943e6a846077a98: Scheduling FlushDeltaMemStoresOp(6482c0062489402e9bd0a263e9265934): perf score=10.126437
I20260812 06:16:54.255714 32065 maintenance_manager.cc:643] P a885aee58dfe45f2a943e6a846077a98: FlushDeltaMemStoresOp(6482c0062489402e9bd0a263e9265934) complete. Timing: real 0.041s	user 0.018s	sys 0.015s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":14360,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:54.256363 32174 maintenance_manager.cc:419] P a885aee58dfe45f2a943e6a846077a98: Scheduling FlushDeltaMemStoresOp(6482c0062489402e9bd0a263e9265934): perf score=2.188937
I20260812 06:16:54.273089 32065 maintenance_manager.cc:643] P a885aee58dfe45f2a943e6a846077a98: FlushDeltaMemStoresOp(6482c0062489402e9bd0a263e9265934) complete. Timing: real 0.016s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5934,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:54.273742 32174 maintenance_manager.cc:419] P a885aee58dfe45f2a943e6a846077a98: Scheduling MajorDeltaCompactionOp(6482c0062489402e9bd0a263e9265934): perf score=1.000000
I20260812 06:16:54.408872 32065 maintenance_manager.cc:643] P a885aee58dfe45f2a943e6a846077a98: MajorDeltaCompactionOp(6482c0062489402e9bd0a263e9265934) complete. Timing: real 0.135s	user 0.090s	sys 0.045s 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":370,"lbm_read_time_us":9759,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26039,"lbm_writes_lt_1ms":443,"mutex_wait_us":23,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":24704,"update_count":2000}
I20260812 06:16:54.409509 32174 maintenance_manager.cc:419] P a885aee58dfe45f2a943e6a846077a98: Scheduling FlushDeltaMemStoresOp(6482c0062489402e9bd0a263e9265934): perf score=10.126437
I20260812 06:16:54.463078 32065 maintenance_manager.cc:643] P a885aee58dfe45f2a943e6a846077a98: FlushDeltaMemStoresOp(6482c0062489402e9bd0a263e9265934) complete. Timing: real 0.053s	user 0.024s	sys 0.023s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15199,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:54.463657 32174 maintenance_manager.cc:419] P a885aee58dfe45f2a943e6a846077a98: Scheduling FlushDeltaMemStoresOp(6482c0062489402e9bd0a263e9265934): perf score=2.188937
I20260812 06:16:54.479710 32065 maintenance_manager.cc:643] P a885aee58dfe45f2a943e6a846077a98: FlushDeltaMemStoresOp(6482c0062489402e9bd0a263e9265934) complete. Timing: real 0.016s	user 0.013s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6151,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:54.480456 32174 maintenance_manager.cc:419] P a885aee58dfe45f2a943e6a846077a98: Scheduling MajorDeltaCompactionOp(6482c0062489402e9bd0a263e9265934): perf score=1.000000
I20260812 06:16:54.643857 32065 maintenance_manager.cc:643] P a885aee58dfe45f2a943e6a846077a98: MajorDeltaCompactionOp(6482c0062489402e9bd0a263e9265934) complete. Timing: real 0.163s	user 0.105s	sys 0.058s 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":1349,"lbm_read_time_us":13067,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25634,"lbm_writes_lt_1ms":443,"mutex_wait_us":342,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:16:54.644639 32174 maintenance_manager.cc:419] P a885aee58dfe45f2a943e6a846077a98: Scheduling FlushDeltaMemStoresOp(6482c0062489402e9bd0a263e9265934): perf score=10.126437
I20260812 06:16:54.694257 32065 maintenance_manager.cc:643] P a885aee58dfe45f2a943e6a846077a98: FlushDeltaMemStoresOp(6482c0062489402e9bd0a263e9265934) complete. Timing: real 0.049s	user 0.030s	sys 0.017s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":22234,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:16:54.694810 32174 maintenance_manager.cc:419] P a885aee58dfe45f2a943e6a846077a98: Scheduling FlushDeltaMemStoresOp(6482c0062489402e9bd0a263e9265934): perf score=2.188937
I20260812 06:16:54.707921 32065 maintenance_manager.cc:643] P a885aee58dfe45f2a943e6a846077a98: FlushDeltaMemStoresOp(6482c0062489402e9bd0a263e9265934) complete. Timing: real 0.013s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4501,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:54.709167 32174 maintenance_manager.cc:419] P a885aee58dfe45f2a943e6a846077a98: Scheduling MajorDeltaCompactionOp(6482c0062489402e9bd0a263e9265934): perf score=1.000000
I20260812 06:16:54.849138 32065 maintenance_manager.cc:643] P a885aee58dfe45f2a943e6a846077a98: MajorDeltaCompactionOp(6482c0062489402e9bd0a263e9265934) complete. Timing: real 0.140s	user 0.102s	sys 0.033s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":876,"lbm_read_time_us":11422,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26639,"lbm_writes_lt_1ms":443,"mutex_wait_us":22,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10240,"update_count":2000}
I20260812 06:16:54.849835 32174 maintenance_manager.cc:419] P a885aee58dfe45f2a943e6a846077a98: Scheduling FlushDeltaMemStoresOp(6482c0062489402e9bd0a263e9265934): perf score=10.126437
I20260812 06:16:54.902688 32065 maintenance_manager.cc:643] P a885aee58dfe45f2a943e6a846077a98: FlushDeltaMemStoresOp(6482c0062489402e9bd0a263e9265934) complete. Timing: real 0.053s	user 0.032s	sys 0.005s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16489,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:54.903257 32174 maintenance_manager.cc:419] P a885aee58dfe45f2a943e6a846077a98: Scheduling FlushDeltaMemStoresOp(6482c0062489402e9bd0a263e9265934): perf score=2.188937
I20260812 06:16:54.915885 32065 maintenance_manager.cc:643] P a885aee58dfe45f2a943e6a846077a98: FlushDeltaMemStoresOp(6482c0062489402e9bd0a263e9265934) complete. Timing: real 0.012s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4543,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:54.916569 32174 maintenance_manager.cc:419] P a885aee58dfe45f2a943e6a846077a98: Scheduling MajorDeltaCompactionOp(6482c0062489402e9bd0a263e9265934): perf score=1.000000
I20260812 06:16:55.044636 32065 maintenance_manager.cc:643] P a885aee58dfe45f2a943e6a846077a98: MajorDeltaCompactionOp(6482c0062489402e9bd0a263e9265934) complete. Timing: real 0.128s	user 0.091s	sys 0.036s 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":226,"lbm_read_time_us":9032,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25876,"lbm_writes_lt_1ms":443,"mutex_wait_us":92,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2000}
I20260812 06:16:55.045399 32174 maintenance_manager.cc:419] P a885aee58dfe45f2a943e6a846077a98: Scheduling FlushDeltaMemStoresOp(6482c0062489402e9bd0a263e9265934): perf score=10.126437
I20260812 06:16:55.090445 32065 maintenance_manager.cc:643] P a885aee58dfe45f2a943e6a846077a98: FlushDeltaMemStoresOp(6482c0062489402e9bd0a263e9265934) complete. Timing: real 0.045s	user 0.026s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16966,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:55.091030 32174 maintenance_manager.cc:419] P a885aee58dfe45f2a943e6a846077a98: Scheduling FlushDeltaMemStoresOp(6482c0062489402e9bd0a263e9265934): perf score=2.188937
I20260812 06:16:55.102545 32065 maintenance_manager.cc:643] P a885aee58dfe45f2a943e6a846077a98: FlushDeltaMemStoresOp(6482c0062489402e9bd0a263e9265934) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4319,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:55.103348 32174 maintenance_manager.cc:419] P a885aee58dfe45f2a943e6a846077a98: Scheduling MajorDeltaCompactionOp(6482c0062489402e9bd0a263e9265934): perf score=1.000000
I20260812 06:16:55.254407 32065 maintenance_manager.cc:643] P a885aee58dfe45f2a943e6a846077a98: MajorDeltaCompactionOp(6482c0062489402e9bd0a263e9265934) complete. Timing: real 0.151s	user 0.106s	sys 0.044s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":977,"lbm_read_time_us":11473,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25187,"lbm_writes_lt_1ms":443,"mutex_wait_us":497,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":21504,"update_count":2000}
I20260812 06:16:55.255177 32174 maintenance_manager.cc:419] P a885aee58dfe45f2a943e6a846077a98: Scheduling FlushDeltaMemStoresOp(6482c0062489402e9bd0a263e9265934): perf score=10.126437
I20260812 06:16:55.287500 32065 maintenance_manager.cc:643] P a885aee58dfe45f2a943e6a846077a98: FlushDeltaMemStoresOp(6482c0062489402e9bd0a263e9265934) complete. Timing: real 0.032s	user 0.018s	sys 0.012s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":14153,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:55.288014 32174 maintenance_manager.cc:419] P a885aee58dfe45f2a943e6a846077a98: Scheduling FlushDeltaMemStoresOp(6482c0062489402e9bd0a263e9265934): perf score=2.188937
I20260812 06:16:55.310895 32065 maintenance_manager.cc:643] P a885aee58dfe45f2a943e6a846077a98: FlushDeltaMemStoresOp(6482c0062489402e9bd0a263e9265934) complete. Timing: real 0.023s	user 0.015s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6640,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:55.311529 32174 maintenance_manager.cc:419] P a885aee58dfe45f2a943e6a846077a98: Scheduling FlushMRSOp(6482c0062489402e9bd0a263e9265934): perf score=1.000000
I20260812 06:16:55.350531 32065 maintenance_manager.cc:643] P a885aee58dfe45f2a943e6a846077a98: FlushMRSOp(6482c0062489402e9bd0a263e9265934) complete. Timing: real 0.039s	user 0.027s	sys 0.000s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":128,"dirs.run_cpu_time_us":336,"dirs.run_wall_time_us":1542,"drs_written":1,"lbm_read_time_us":107,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1545,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28,"spinlock_wait_cycles":25344}
I20260812 06:16:55.351341 32174 maintenance_manager.cc:419] P a885aee58dfe45f2a943e6a846077a98: Scheduling UndoDeltaBlockGCOp(6482c0062489402e9bd0a263e9265934): 447 bytes on disk
I20260812 06:16:55.351969 32065 maintenance_manager.cc:643] P a885aee58dfe45f2a943e6a846077a98: UndoDeltaBlockGCOp(6482c0062489402e9bd0a263e9265934) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4}
I20260812 06:16:55.352550 32174 maintenance_manager.cc:419] P a885aee58dfe45f2a943e6a846077a98: Scheduling FlushDeltaMemStoresOp(6482c0062489402e9bd0a263e9265934): perf score=3.181125
I20260812 06:16:55.372754 32065 maintenance_manager.cc:643] P a885aee58dfe45f2a943e6a846077a98: FlushDeltaMemStoresOp(6482c0062489402e9bd0a263e9265934) complete. Timing: real 0.020s	user 0.007s	sys 0.007s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4523,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:16:55.373495 32174 maintenance_manager.cc:419] P a885aee58dfe45f2a943e6a846077a98: Scheduling LogGCOp(6482c0062489402e9bd0a263e9265934): free 112692371 bytes of WAL
I20260812 06:16:55.373800 32065 log_reader.cc:385] T 6482c0062489402e9bd0a263e9265934: removed 11 log segments from log reader
I20260812 06:16:55.373891 32065 log.cc:1079] T 6482c0062489402e9bd0a263e9265934 P a885aee58dfe45f2a943e6a846077a98: Deleting log segment in path: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515407455541-31521-0/minicluster-data/ts-0-root/wals/6482c0062489402e9bd0a263e9265934/wal-000000003 (ops 12-16)
I20260812 06:16:55.374006 32065 log.cc:1079] T 6482c0062489402e9bd0a263e9265934 P a885aee58dfe45f2a943e6a846077a98: Deleting log segment in path: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515407455541-31521-0/minicluster-data/ts-0-root/wals/6482c0062489402e9bd0a263e9265934/wal-000000004 (ops 17-21)
I20260812 06:16:55.374058 32065 log.cc:1079] T 6482c0062489402e9bd0a263e9265934 P a885aee58dfe45f2a943e6a846077a98: Deleting log segment in path: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515407455541-31521-0/minicluster-data/ts-0-root/wals/6482c0062489402e9bd0a263e9265934/wal-000000005 (ops 22-26)
I20260812 06:16:55.374094 32065 log.cc:1079] T 6482c0062489402e9bd0a263e9265934 P a885aee58dfe45f2a943e6a846077a98: Deleting log segment in path: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515407455541-31521-0/minicluster-data/ts-0-root/wals/6482c0062489402e9bd0a263e9265934/wal-000000006 (ops 27-31)
I20260812 06:16:55.374171 32065 log.cc:1079] T 6482c0062489402e9bd0a263e9265934 P a885aee58dfe45f2a943e6a846077a98: Deleting log segment in path: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515407455541-31521-0/minicluster-data/ts-0-root/wals/6482c0062489402e9bd0a263e9265934/wal-000000007 (ops 32-36)
I20260812 06:16:55.374217 32065 log.cc:1079] T 6482c0062489402e9bd0a263e9265934 P a885aee58dfe45f2a943e6a846077a98: Deleting log segment in path: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515407455541-31521-0/minicluster-data/ts-0-root/wals/6482c0062489402e9bd0a263e9265934/wal-000000008 (ops 37-41)
I20260812 06:16:55.374289 32065 log.cc:1079] T 6482c0062489402e9bd0a263e9265934 P a885aee58dfe45f2a943e6a846077a98: Deleting log segment in path: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515407455541-31521-0/minicluster-data/ts-0-root/wals/6482c0062489402e9bd0a263e9265934/wal-000000009 (ops 42-46)
I20260812 06:16:55.374347 32065 log.cc:1079] T 6482c0062489402e9bd0a263e9265934 P a885aee58dfe45f2a943e6a846077a98: Deleting log segment in path: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515407455541-31521-0/minicluster-data/ts-0-root/wals/6482c0062489402e9bd0a263e9265934/wal-000000010 (ops 47-51)
I20260812 06:16:55.374382 32065 log.cc:1079] T 6482c0062489402e9bd0a263e9265934 P a885aee58dfe45f2a943e6a846077a98: Deleting log segment in path: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515407455541-31521-0/minicluster-data/ts-0-root/wals/6482c0062489402e9bd0a263e9265934/wal-000000011 (ops 52-56)
I20260812 06:16:55.374451 32065 log.cc:1079] T 6482c0062489402e9bd0a263e9265934 P a885aee58dfe45f2a943e6a846077a98: Deleting log segment in path: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515407455541-31521-0/minicluster-data/ts-0-root/wals/6482c0062489402e9bd0a263e9265934/wal-000000012 (ops 57-61)
I20260812 06:16:55.374500 32065 log.cc:1079] T 6482c0062489402e9bd0a263e9265934 P a885aee58dfe45f2a943e6a846077a98: Deleting log segment in path: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515407455541-31521-0/minicluster-data/ts-0-root/wals/6482c0062489402e9bd0a263e9265934/wal-000000013 (ops 62-66)
I20260812 06:16:55.402658 32065 maintenance_manager.cc:643] P a885aee58dfe45f2a943e6a846077a98: LogGCOp(6482c0062489402e9bd0a263e9265934) complete. Timing: real 0.029s	user 0.001s	sys 0.027s Metrics: {}
I20260812 06:16:55.403101 32174 maintenance_manager.cc:419] P a885aee58dfe45f2a943e6a846077a98: Scheduling FlushDeltaMemStoresOp(6482c0062489402e9bd0a263e9265934): perf score=2.188937
I20260812 06:16:55.424270 32065 maintenance_manager.cc:643] P a885aee58dfe45f2a943e6a846077a98: FlushDeltaMemStoresOp(6482c0062489402e9bd0a263e9265934) complete. Timing: real 0.021s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4249,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:55.424875 32174 maintenance_manager.cc:419] P a885aee58dfe45f2a943e6a846077a98: Scheduling FlushDeltaMemStoresOp(6482c0062489402e9bd0a263e9265934): perf score=2.188937
I20260812 06:16:55.440490 32065 maintenance_manager.cc:643] P a885aee58dfe45f2a943e6a846077a98: FlushDeltaMemStoresOp(6482c0062489402e9bd0a263e9265934) complete. Timing: real 0.015s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5793,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:55.441172 32174 maintenance_manager.cc:419] P a885aee58dfe45f2a943e6a846077a98: Scheduling MajorDeltaCompactionOp(6482c0062489402e9bd0a263e9265934): perf score=1.000000
I20260812 06:16:55.694228 32065 maintenance_manager.cc:643] P a885aee58dfe45f2a943e6a846077a98: MajorDeltaCompactionOp(6482c0062489402e9bd0a263e9265934) complete. Timing: real 0.253s	user 0.161s	sys 0.087s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32979858,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":1026,"lbm_read_time_us":16371,"lbm_reads_lt_1ms":775,"lbm_write_time_us":41864,"lbm_writes_lt_1ms":743,"mutex_wait_us":24,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":34688,"thread_start_us":123,"threads_started":1,"update_count":3500}
I20260812 06:16:55.696296 32174 maintenance_manager.cc:419] P a885aee58dfe45f2a943e6a846077a98: Scheduling FlushDeltaMemStoresOp(6482c0062489402e9bd0a263e9265934): perf score=17.071750
I20260812 06:16:55.745635 32065 maintenance_manager.cc:643] P a885aee58dfe45f2a943e6a846077a98: FlushDeltaMemStoresOp(6482c0062489402e9bd0a263e9265934) complete. Timing: real 0.049s	user 0.025s	sys 0.020s Metrics: {"bytes_written":18666229,"delete_count":0,"lbm_write_time_us":22022,"lbm_writes_lt_1ms":458,"reinsert_count":0,"update_count":2275}
I20260812 06:16:55.746330 32174 maintenance_manager.cc:419] P a885aee58dfe45f2a943e6a846077a98: Scheduling FlushDeltaMemStoresOp(6482c0062489402e9bd0a263e9265934): perf score=1.000000
I20260812 06:16:55.766520 32065 maintenance_manager.cc:643] P a885aee58dfe45f2a943e6a846077a98: FlushDeltaMemStoresOp(6482c0062489402e9bd0a263e9265934) complete. Timing: real 0.020s	user 0.008s	sys 0.000s Metrics: {"bytes_written":1846277,"delete_count":0,"lbm_write_time_us":2791,"lbm_writes_lt_1ms":48,"reinsert_count":0,"update_count":225}
I20260812 06:16:55.767009 32174 maintenance_manager.cc:419] P a885aee58dfe45f2a943e6a846077a98: Scheduling FlushDeltaMemStoresOp(6482c0062489402e9bd0a263e9265934): perf score=2.188937
I20260812 06:16:55.778100 32065 maintenance_manager.cc:643] P a885aee58dfe45f2a943e6a846077a98: FlushDeltaMemStoresOp(6482c0062489402e9bd0a263e9265934) complete. Timing: real 0.011s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4237,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:55.778688 32174 maintenance_manager.cc:419] P a885aee58dfe45f2a943e6a846077a98: Scheduling MajorDeltaCompactionOp(6482c0062489402e9bd0a263e9265934): perf score=1.000000
I20260812 06:16:55.992693 32065 maintenance_manager.cc:643] P a885aee58dfe45f2a943e6a846077a98: MajorDeltaCompactionOp(6482c0062489402e9bd0a263e9265934) complete. Timing: real 0.214s	user 0.154s	sys 0.060s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877166,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":330,"lbm_read_time_us":12960,"lbm_reads_lt_1ms":673,"lbm_write_time_us":36082,"lbm_writes_lt_1ms":643,"mutex_wait_us":35,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":18048,"update_count":3000}
I20260812 06:16:55.993629 32174 maintenance_manager.cc:419] P a885aee58dfe45f2a943e6a846077a98: Scheduling FlushDeltaMemStoresOp(6482c0062489402e9bd0a263e9265934): perf score=14.095187
I20260812 06:16:56.041015 32065 maintenance_manager.cc:643] P a885aee58dfe45f2a943e6a846077a98: FlushDeltaMemStoresOp(6482c0062489402e9bd0a263e9265934) complete. Timing: real 0.047s	user 0.031s	sys 0.013s Metrics: {"bytes_written":16409907,"delete_count":0,"lbm_write_time_us":20786,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:56.042233 32174 maintenance_manager.cc:419] P a885aee58dfe45f2a943e6a846077a98: Scheduling FlushDeltaMemStoresOp(6482c0062489402e9bd0a263e9265934): perf score=2.188937
I20260812 06:16:56.053661 32065 maintenance_manager.cc:643] P a885aee58dfe45f2a943e6a846077a98: FlushDeltaMemStoresOp(6482c0062489402e9bd0a263e9265934) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4484,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:56.054433 32174 maintenance_manager.cc:419] P a885aee58dfe45f2a943e6a846077a98: Scheduling MajorDeltaCompactionOp(6482c0062489402e9bd0a263e9265934): perf score=1.000000
I20260812 06:16:56.241904 32065 maintenance_manager.cc:643] P a885aee58dfe45f2a943e6a846077a98: MajorDeltaCompactionOp(6482c0062489402e9bd0a263e9265934) complete. Timing: real 0.187s	user 0.147s	sys 0.034s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774694,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":941,"lbm_read_time_us":12983,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29497,"lbm_writes_lt_1ms":543,"mutex_wait_us":92,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2816,"update_count":2500}
I20260812 06:16:56.242522 32174 maintenance_manager.cc:419] P a885aee58dfe45f2a943e6a846077a98: Scheduling FlushDeltaMemStoresOp(6482c0062489402e9bd0a263e9265934): perf score=14.095187
I20260812 06:16:56.308910 32065 maintenance_manager.cc:643] P a885aee58dfe45f2a943e6a846077a98: FlushDeltaMemStoresOp(6482c0062489402e9bd0a263e9265934) complete. Timing: real 0.066s	user 0.030s	sys 0.024s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":24862,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:56.309454 32174 maintenance_manager.cc:419] P a885aee58dfe45f2a943e6a846077a98: Scheduling FlushDeltaMemStoresOp(6482c0062489402e9bd0a263e9265934): perf score=2.188937
I20260812 06:16:56.321154 32065 maintenance_manager.cc:643] P a885aee58dfe45f2a943e6a846077a98: FlushDeltaMemStoresOp(6482c0062489402e9bd0a263e9265934) complete. Timing: real 0.012s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4271,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:56.321964 32174 maintenance_manager.cc:419] P a885aee58dfe45f2a943e6a846077a98: Scheduling MajorDeltaCompactionOp(6482c0062489402e9bd0a263e9265934): perf score=1.000000
I20260812 06:16:56.501711 32065 maintenance_manager.cc:643] P a885aee58dfe45f2a943e6a846077a98: MajorDeltaCompactionOp(6482c0062489402e9bd0a263e9265934) complete. Timing: real 0.179s	user 0.112s	sys 0.066s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1261,"lbm_read_time_us":13294,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30432,"lbm_writes_lt_1ms":543,"mutex_wait_us":415,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":253440,"update_count":2500}
I20260812 06:16:56.502597 32174 maintenance_manager.cc:419] P a885aee58dfe45f2a943e6a846077a98: Scheduling FlushDeltaMemStoresOp(6482c0062489402e9bd0a263e9265934): perf score=11.118625
I20260812 06:16:56.549516 32065 maintenance_manager.cc:643] P a885aee58dfe45f2a943e6a846077a98: FlushDeltaMemStoresOp(6482c0062489402e9bd0a263e9265934) complete. Timing: real 0.047s	user 0.033s	sys 0.007s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":19182,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:16:56.550503 32174 maintenance_manager.cc:419] P a885aee58dfe45f2a943e6a846077a98: Scheduling FlushDeltaMemStoresOp(6482c0062489402e9bd0a263e9265934): perf score=2.188937
I20260812 06:16:56.574381 32065 maintenance_manager.cc:643] P a885aee58dfe45f2a943e6a846077a98: FlushDeltaMemStoresOp(6482c0062489402e9bd0a263e9265934) complete. Timing: real 0.024s	user 0.010s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7341,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:56.574909 32174 maintenance_manager.cc:419] P a885aee58dfe45f2a943e6a846077a98: Scheduling FlushDeltaMemStoresOp(6482c0062489402e9bd0a263e9265934): perf score=2.188937
I20260812 06:16:56.586586 32065 maintenance_manager.cc:643] P a885aee58dfe45f2a943e6a846077a98: FlushDeltaMemStoresOp(6482c0062489402e9bd0a263e9265934) complete. Timing: real 0.011s	user 0.003s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4468,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:56.587177 32174 maintenance_manager.cc:419] P a885aee58dfe45f2a943e6a846077a98: Scheduling MajorDeltaCompactionOp(6482c0062489402e9bd0a263e9265934): perf score=1.000000
I20260812 06:16:56.795871 32065 maintenance_manager.cc:643] P a885aee58dfe45f2a943e6a846077a98: MajorDeltaCompactionOp(6482c0062489402e9bd0a263e9265934) complete. Timing: real 0.209s	user 0.153s	sys 0.048s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774799,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":789,"lbm_read_time_us":14656,"lbm_reads_lt_1ms":573,"lbm_write_time_us":32187,"lbm_writes_lt_1ms":543,"mutex_wait_us":338,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8960,"update_count":2500}
I20260812 06:16:56.796433 32174 maintenance_manager.cc:419] P a885aee58dfe45f2a943e6a846077a98: Scheduling FlushDeltaMemStoresOp(6482c0062489402e9bd0a263e9265934): perf score=14.095187
I20260812 06:16:56.865473 32065 maintenance_manager.cc:643] P a885aee58dfe45f2a943e6a846077a98: FlushDeltaMemStoresOp(6482c0062489402e9bd0a263e9265934) complete. Timing: real 0.069s	user 0.036s	sys 0.026s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24552,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:56.866171 32174 maintenance_manager.cc:419] P a885aee58dfe45f2a943e6a846077a98: Scheduling FlushDeltaMemStoresOp(6482c0062489402e9bd0a263e9265934): perf score=2.188937
I20260812 06:16:56.877601 32065 maintenance_manager.cc:643] P a885aee58dfe45f2a943e6a846077a98: FlushDeltaMemStoresOp(6482c0062489402e9bd0a263e9265934) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4389,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:56.878209 32174 maintenance_manager.cc:419] P a885aee58dfe45f2a943e6a846077a98: Scheduling FlushMRSOp(6482c0062489402e9bd0a263e9265934): perf score=1.000000
I20260812 06:16:56.911784 32065 maintenance_manager.cc:643] P a885aee58dfe45f2a943e6a846077a98: FlushMRSOp(6482c0062489402e9bd0a263e9265934) complete. Timing: real 0.033s	user 0.028s	sys 0.000s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":88,"dirs.run_cpu_time_us":269,"dirs.run_wall_time_us":1630,"drs_written":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1455,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:16:56.912516 32174 maintenance_manager.cc:419] P a885aee58dfe45f2a943e6a846077a98: Scheduling UndoDeltaBlockGCOp(6482c0062489402e9bd0a263e9265934): 447 bytes on disk
I20260812 06:16:56.913023 32065 maintenance_manager.cc:643] P a885aee58dfe45f2a943e6a846077a98: UndoDeltaBlockGCOp(6482c0062489402e9bd0a263e9265934) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":70,"lbm_reads_lt_1ms":4}
I20260812 06:16:56.913635 32174 maintenance_manager.cc:419] P a885aee58dfe45f2a943e6a846077a98: Scheduling MajorDeltaCompactionOp(6482c0062489402e9bd0a263e9265934): perf score=1.000000
I20260812 06:16:57.106585 32065 maintenance_manager.cc:643] P a885aee58dfe45f2a943e6a846077a98: MajorDeltaCompactionOp(6482c0062489402e9bd0a263e9265934) complete. Timing: real 0.193s	user 0.132s	sys 0.060s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":320,"lbm_read_time_us":12176,"lbm_reads_lt_1ms":564,"lbm_write_time_us":29627,"lbm_writes_lt_1ms":543,"mutex_wait_us":59,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2500}
I20260812 06:16:57.107391 32174 maintenance_manager.cc:419] P a885aee58dfe45f2a943e6a846077a98: Scheduling LogGCOp(6482c0062489402e9bd0a263e9265934): free 120100333 bytes of WAL
I20260812 06:16:57.107764 32065 log_reader.cc:385] T 6482c0062489402e9bd0a263e9265934: removed 12 log segments from log reader
I20260812 06:16:57.107874 32065 log.cc:1079] T 6482c0062489402e9bd0a263e9265934 P a885aee58dfe45f2a943e6a846077a98: Deleting log segment in path: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515407455541-31521-0/minicluster-data/ts-0-root/wals/6482c0062489402e9bd0a263e9265934/wal-000000014 (ops 67-70)
I20260812 06:16:57.108011 32065 log.cc:1079] T 6482c0062489402e9bd0a263e9265934 P a885aee58dfe45f2a943e6a846077a98: Deleting log segment in path: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515407455541-31521-0/minicluster-data/ts-0-root/wals/6482c0062489402e9bd0a263e9265934/wal-000000015 (ops 71-75)
I20260812 06:16:57.108104 32065 log.cc:1079] T 6482c0062489402e9bd0a263e9265934 P a885aee58dfe45f2a943e6a846077a98: Deleting log segment in path: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515407455541-31521-0/minicluster-data/ts-0-root/wals/6482c0062489402e9bd0a263e9265934/wal-000000016 (ops 76-80)
I20260812 06:16:57.108196 32065 log.cc:1079] T 6482c0062489402e9bd0a263e9265934 P a885aee58dfe45f2a943e6a846077a98: Deleting log segment in path: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515407455541-31521-0/minicluster-data/ts-0-root/wals/6482c0062489402e9bd0a263e9265934/wal-000000017 (ops 81-84)
I20260812 06:16:57.108287 32065 log.cc:1079] T 6482c0062489402e9bd0a263e9265934 P a885aee58dfe45f2a943e6a846077a98: Deleting log segment in path: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515407455541-31521-0/minicluster-data/ts-0-root/wals/6482c0062489402e9bd0a263e9265934/wal-000000018 (ops 85-89)
I20260812 06:16:57.108355 32065 log.cc:1079] T 6482c0062489402e9bd0a263e9265934 P a885aee58dfe45f2a943e6a846077a98: Deleting log segment in path: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515407455541-31521-0/minicluster-data/ts-0-root/wals/6482c0062489402e9bd0a263e9265934/wal-000000019 (ops 90-94)
I20260812 06:16:57.108435 32065 log.cc:1079] T 6482c0062489402e9bd0a263e9265934 P a885aee58dfe45f2a943e6a846077a98: Deleting log segment in path: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515407455541-31521-0/minicluster-data/ts-0-root/wals/6482c0062489402e9bd0a263e9265934/wal-000000020 (ops 95-99)
I20260812 06:16:57.108500 32065 log.cc:1079] T 6482c0062489402e9bd0a263e9265934 P a885aee58dfe45f2a943e6a846077a98: Deleting log segment in path: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515407455541-31521-0/minicluster-data/ts-0-root/wals/6482c0062489402e9bd0a263e9265934/wal-000000021 (ops 100-104)
I20260812 06:16:57.108560 32065 log.cc:1079] T 6482c0062489402e9bd0a263e9265934 P a885aee58dfe45f2a943e6a846077a98: Deleting log segment in path: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515407455541-31521-0/minicluster-data/ts-0-root/wals/6482c0062489402e9bd0a263e9265934/wal-000000022 (ops 105-108)
I20260812 06:16:57.108615 32065 log.cc:1079] T 6482c0062489402e9bd0a263e9265934 P a885aee58dfe45f2a943e6a846077a98: Deleting log segment in path: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515407455541-31521-0/minicluster-data/ts-0-root/wals/6482c0062489402e9bd0a263e9265934/wal-000000023 (ops 109-113)
I20260812 06:16:57.108711 32065 log.cc:1079] T 6482c0062489402e9bd0a263e9265934 P a885aee58dfe45f2a943e6a846077a98: Deleting log segment in path: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515407455541-31521-0/minicluster-data/ts-0-root/wals/6482c0062489402e9bd0a263e9265934/wal-000000024 (ops 114-118)
I20260812 06:16:57.108776 32065 log.cc:1079] T 6482c0062489402e9bd0a263e9265934 P a885aee58dfe45f2a943e6a846077a98: Deleting log segment in path: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515407455541-31521-0/minicluster-data/ts-0-root/wals/6482c0062489402e9bd0a263e9265934/wal-000000025 (ops 119-123)
I20260812 06:16:57.139067 32065 maintenance_manager.cc:643] P a885aee58dfe45f2a943e6a846077a98: LogGCOp(6482c0062489402e9bd0a263e9265934) complete. Timing: real 0.031s	user 0.000s	sys 0.030s Metrics: {}
I20260812 06:16:57.139544 32174 maintenance_manager.cc:419] P a885aee58dfe45f2a943e6a846077a98: Scheduling FlushDeltaMemStoresOp(6482c0062489402e9bd0a263e9265934): perf score=16.079562
I20260812 06:16:57.202147 32065 maintenance_manager.cc:643] P a885aee58dfe45f2a943e6a846077a98: FlushDeltaMemStoresOp(6482c0062489402e9bd0a263e9265934) complete. Timing: real 0.062s	user 0.027s	sys 0.032s Metrics: {"bytes_written":18502132,"delete_count":0,"lbm_write_time_us":21845,"lbm_writes_lt_1ms":454,"reinsert_count":0,"update_count":2255}
I20260812 06:16:57.202739 32174 maintenance_manager.cc:419] P a885aee58dfe45f2a943e6a846077a98: Scheduling FlushDeltaMemStoresOp(6482c0062489402e9bd0a263e9265934): perf score=4.173312
I20260812 06:16:57.220116 32065 maintenance_manager.cc:643] P a885aee58dfe45f2a943e6a846077a98: FlushDeltaMemStoresOp(6482c0062489402e9bd0a263e9265934) complete. Timing: real 0.017s	user 0.013s	sys 0.001s Metrics: {"bytes_written":6112856,"delete_count":0,"lbm_write_time_us":6664,"lbm_writes_lt_1ms":152,"reinsert_count":0,"update_count":745}
I20260812 06:16:57.220709 32174 maintenance_manager.cc:419] P a885aee58dfe45f2a943e6a846077a98: Scheduling MajorDeltaCompactionOp(6482c0062489402e9bd0a263e9265934): perf score=1.000000
I20260812 06:16:57.428892 32065 maintenance_manager.cc:643] P a885aee58dfe45f2a943e6a846077a98: MajorDeltaCompactionOp(6482c0062489402e9bd0a263e9265934) complete. Timing: real 0.208s	user 0.148s	sys 0.060s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877110,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":556,"lbm_read_time_us":15383,"lbm_reads_lt_1ms":672,"lbm_write_time_us":37831,"lbm_writes_lt_1ms":643,"mutex_wait_us":72,"peak_mem_usage":75542472,"reinsert_count":0,"update_count":3000}
I20260812 06:16:57.429647 32174 maintenance_manager.cc:419] P a885aee58dfe45f2a943e6a846077a98: Scheduling FlushDeltaMemStoresOp(6482c0062489402e9bd0a263e9265934): perf score=14.095187
I20260812 06:16:57.503225 32065 maintenance_manager.cc:643] P a885aee58dfe45f2a943e6a846077a98: FlushDeltaMemStoresOp(6482c0062489402e9bd0a263e9265934) complete. Timing: real 0.073s	user 0.033s	sys 0.038s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":27851,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:16:57.503795 32174 maintenance_manager.cc:419] P a885aee58dfe45f2a943e6a846077a98: Scheduling FlushDeltaMemStoresOp(6482c0062489402e9bd0a263e9265934): perf score=2.188937
I20260812 06:16:57.519280 32065 maintenance_manager.cc:643] P a885aee58dfe45f2a943e6a846077a98: FlushDeltaMemStoresOp(6482c0062489402e9bd0a263e9265934) complete. Timing: real 0.015s	user 0.008s	sys 0.003s Metrics: {"bytes_written":4184708,"delete_count":0,"lbm_write_time_us":4748,"lbm_writes_lt_1ms":105,"reinsert_count":0,"update_count":510}
I20260812 06:16:57.519804 32174 maintenance_manager.cc:419] P a885aee58dfe45f2a943e6a846077a98: Scheduling FlushDeltaMemStoresOp(6482c0062489402e9bd0a263e9265934): perf score=2.188937
I20260812 06:16:57.530813 32065 maintenance_manager.cc:643] P a885aee58dfe45f2a943e6a846077a98: FlushDeltaMemStoresOp(6482c0062489402e9bd0a263e9265934) complete. Timing: real 0.011s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4020608,"delete_count":0,"lbm_write_time_us":4385,"lbm_writes_lt_1ms":101,"reinsert_count":0,"update_count":490}
I20260812 06:16:57.531308 32174 maintenance_manager.cc:419] P a885aee58dfe45f2a943e6a846077a98: Scheduling MajorDeltaCompactionOp(6482c0062489402e9bd0a263e9265934): perf score=1.000000
I20260812 06:16:57.748708 32065 maintenance_manager.cc:643] P a885aee58dfe45f2a943e6a846077a98: MajorDeltaCompactionOp(6482c0062489402e9bd0a263e9265934) complete. Timing: real 0.217s	user 0.155s	sys 0.057s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877217,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":494,"lbm_read_time_us":14304,"lbm_reads_lt_1ms":673,"lbm_write_time_us":33777,"lbm_writes_lt_1ms":643,"mutex_wait_us":1,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":6656,"update_count":3000}
I20260812 06:16:57.749944 32174 maintenance_manager.cc:419] P a885aee58dfe45f2a943e6a846077a98: Scheduling FlushDeltaMemStoresOp(6482c0062489402e9bd0a263e9265934): perf score=16.079562
I20260812 06:16:57.808058 32065 maintenance_manager.cc:643] P a885aee58dfe45f2a943e6a846077a98: FlushDeltaMemStoresOp(6482c0062489402e9bd0a263e9265934) complete. Timing: real 0.058s	user 0.031s	sys 0.024s Metrics: {"bytes_written":17681652,"delete_count":0,"lbm_write_time_us":26073,"lbm_writes_lt_1ms":434,"reinsert_count":0,"update_count":2155}
I20260812 06:16:57.808681 32174 maintenance_manager.cc:419] P a885aee58dfe45f2a943e6a846077a98: Scheduling FlushDeltaMemStoresOp(6482c0062489402e9bd0a263e9265934): perf score=2.188937
I20260812 06:16:57.819957 32065 maintenance_manager.cc:643] P a885aee58dfe45f2a943e6a846077a98: FlushDeltaMemStoresOp(6482c0062489402e9bd0a263e9265934) complete. Timing: real 0.011s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3241134,"delete_count":0,"lbm_write_time_us":3576,"lbm_writes_lt_1ms":82,"reinsert_count":0,"update_count":395}
I20260812 06:16:57.820482 32174 maintenance_manager.cc:419] P a885aee58dfe45f2a943e6a846077a98: Scheduling FlushDeltaMemStoresOp(6482c0062489402e9bd0a263e9265934): perf score=2.188937
I20260812 06:16:57.830806 32065 maintenance_manager.cc:643] P a885aee58dfe45f2a943e6a846077a98: FlushDeltaMemStoresOp(6482c0062489402e9bd0a263e9265934) complete. Timing: real 0.010s	user 0.004s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3881,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:57.831351 32174 maintenance_manager.cc:419] P a885aee58dfe45f2a943e6a846077a98: Scheduling MajorDeltaCompactionOp(6482c0062489402e9bd0a263e9265934): perf score=1.000000
I20260812 06:16:58.032913 32065 maintenance_manager.cc:643] P a885aee58dfe45f2a943e6a846077a98: MajorDeltaCompactionOp(6482c0062489402e9bd0a263e9265934) complete. Timing: real 0.201s	user 0.179s	sys 0.021s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877191,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1262,"lbm_read_time_us":15450,"lbm_reads_lt_1ms":673,"lbm_write_time_us":31870,"lbm_writes_lt_1ms":643,"mutex_wait_us":396,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":40448,"update_count":3000}
I20260812 06:16:58.033769 32174 maintenance_manager.cc:419] P a885aee58dfe45f2a943e6a846077a98: Scheduling FlushDeltaMemStoresOp(6482c0062489402e9bd0a263e9265934): perf score=14.095187
I20260812 06:16:58.097443 32065 maintenance_manager.cc:643] P a885aee58dfe45f2a943e6a846077a98: FlushDeltaMemStoresOp(6482c0062489402e9bd0a263e9265934) complete. Timing: real 0.063s	user 0.042s	sys 0.013s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":25536,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:58.098150 32174 maintenance_manager.cc:419] P a885aee58dfe45f2a943e6a846077a98: Scheduling FlushDeltaMemStoresOp(6482c0062489402e9bd0a263e9265934): perf score=2.188937
I20260812 06:16:58.112857 32065 maintenance_manager.cc:643] P a885aee58dfe45f2a943e6a846077a98: FlushDeltaMemStoresOp(6482c0062489402e9bd0a263e9265934) complete. Timing: real 0.015s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5319,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:58.113368 32174 maintenance_manager.cc:419] P a885aee58dfe45f2a943e6a846077a98: Scheduling MajorDeltaCompactionOp(6482c0062489402e9bd0a263e9265934): perf score=1.000000
I20260812 06:16:58.311215 32065 maintenance_manager.cc:643] P a885aee58dfe45f2a943e6a846077a98: MajorDeltaCompactionOp(6482c0062489402e9bd0a263e9265934) complete. Timing: real 0.198s	user 0.147s	sys 0.050s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774692,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":258,"lbm_read_time_us":14581,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34491,"lbm_writes_lt_1ms":543,"mutex_wait_us":48,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14336,"update_count":2500}
I20260812 06:16:58.311838 32174 maintenance_manager.cc:419] P a885aee58dfe45f2a943e6a846077a98: Scheduling FlushDeltaMemStoresOp(6482c0062489402e9bd0a263e9265934): perf score=14.095187
I20260812 06:16:58.372957 32065 maintenance_manager.cc:643] P a885aee58dfe45f2a943e6a846077a98: FlushDeltaMemStoresOp(6482c0062489402e9bd0a263e9265934) complete. Timing: real 0.061s	user 0.034s	sys 0.017s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23117,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:58.373524 32174 maintenance_manager.cc:419] P a885aee58dfe45f2a943e6a846077a98: Scheduling FlushDeltaMemStoresOp(6482c0062489402e9bd0a263e9265934): perf score=2.188937
I20260812 06:16:58.385707 32065 maintenance_manager.cc:643] P a885aee58dfe45f2a943e6a846077a98: FlushDeltaMemStoresOp(6482c0062489402e9bd0a263e9265934) complete. Timing: real 0.012s	user 0.007s	sys 0.002s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4396,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:58.386682 32174 maintenance_manager.cc:419] P a885aee58dfe45f2a943e6a846077a98: Scheduling FlushMRSOp(6482c0062489402e9bd0a263e9265934): perf score=1.000000
I20260812 06:16:58.421597 32065 maintenance_manager.cc:643] P a885aee58dfe45f2a943e6a846077a98: FlushMRSOp(6482c0062489402e9bd0a263e9265934) complete. Timing: real 0.035s	user 0.029s	sys 0.004s Metrics: {"bytes_written":1152510,"cfile_init":1,"dirs.queue_time_us":46,"dirs.run_cpu_time_us":301,"dirs.run_wall_time_us":1638,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2164,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:16:58.422370 32174 maintenance_manager.cc:419] P a885aee58dfe45f2a943e6a846077a98: Scheduling LogGCOp(6482c0062489402e9bd0a263e9265934): free 108535688 bytes of WAL
I20260812 06:16:58.422624 32065 log_reader.cc:385] T 6482c0062489402e9bd0a263e9265934: removed 11 log segments from log reader
I20260812 06:16:58.422673 32065 log.cc:1079] T 6482c0062489402e9bd0a263e9265934 P a885aee58dfe45f2a943e6a846077a98: Deleting log segment in path: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515407455541-31521-0/minicluster-data/ts-0-root/wals/6482c0062489402e9bd0a263e9265934/wal-000000026 (ops 124-128)
I20260812 06:16:58.422730 32065 log.cc:1079] T 6482c0062489402e9bd0a263e9265934 P a885aee58dfe45f2a943e6a846077a98: Deleting log segment in path: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515407455541-31521-0/minicluster-data/ts-0-root/wals/6482c0062489402e9bd0a263e9265934/wal-000000027 (ops 129-133)
I20260812 06:16:58.422777 32065 log.cc:1079] T 6482c0062489402e9bd0a263e9265934 P a885aee58dfe45f2a943e6a846077a98: Deleting log segment in path: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515407455541-31521-0/minicluster-data/ts-0-root/wals/6482c0062489402e9bd0a263e9265934/wal-000000028 (ops 134-138)
I20260812 06:16:58.422847 32065 log.cc:1079] T 6482c0062489402e9bd0a263e9265934 P a885aee58dfe45f2a943e6a846077a98: Deleting log segment in path: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515407455541-31521-0/minicluster-data/ts-0-root/wals/6482c0062489402e9bd0a263e9265934/wal-000000029 (ops 139-143)
I20260812 06:16:58.422884 32065 log.cc:1079] T 6482c0062489402e9bd0a263e9265934 P a885aee58dfe45f2a943e6a846077a98: Deleting log segment in path: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515407455541-31521-0/minicluster-data/ts-0-root/wals/6482c0062489402e9bd0a263e9265934/wal-000000030 (ops 144-148)
I20260812 06:16:58.422945 32065 log.cc:1079] T 6482c0062489402e9bd0a263e9265934 P a885aee58dfe45f2a943e6a846077a98: Deleting log segment in path: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515407455541-31521-0/minicluster-data/ts-0-root/wals/6482c0062489402e9bd0a263e9265934/wal-000000031 (ops 149-152)
I20260812 06:16:58.422986 32065 log.cc:1079] T 6482c0062489402e9bd0a263e9265934 P a885aee58dfe45f2a943e6a846077a98: Deleting log segment in path: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515407455541-31521-0/minicluster-data/ts-0-root/wals/6482c0062489402e9bd0a263e9265934/wal-000000032 (ops 153-157)
I20260812 06:16:58.423025 32065 log.cc:1079] T 6482c0062489402e9bd0a263e9265934 P a885aee58dfe45f2a943e6a846077a98: Deleting log segment in path: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515407455541-31521-0/minicluster-data/ts-0-root/wals/6482c0062489402e9bd0a263e9265934/wal-000000033 (ops 158-162)
I20260812 06:16:58.423065 32065 log.cc:1079] T 6482c0062489402e9bd0a263e9265934 P a885aee58dfe45f2a943e6a846077a98: Deleting log segment in path: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515407455541-31521-0/minicluster-data/ts-0-root/wals/6482c0062489402e9bd0a263e9265934/wal-000000034 (ops 163-166)
I20260812 06:16:58.423105 32065 log.cc:1079] T 6482c0062489402e9bd0a263e9265934 P a885aee58dfe45f2a943e6a846077a98: Deleting log segment in path: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515407455541-31521-0/minicluster-data/ts-0-root/wals/6482c0062489402e9bd0a263e9265934/wal-000000035 (ops 167-171)
I20260812 06:16:58.423149 32065 log.cc:1079] T 6482c0062489402e9bd0a263e9265934 P a885aee58dfe45f2a943e6a846077a98: Deleting log segment in path: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515407455541-31521-0/minicluster-data/ts-0-root/wals/6482c0062489402e9bd0a263e9265934/wal-000000036 (ops 172-176)
I20260812 06:16:58.448516 32065 maintenance_manager.cc:643] P a885aee58dfe45f2a943e6a846077a98: LogGCOp(6482c0062489402e9bd0a263e9265934) complete. Timing: real 0.026s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:16:58.449002 32174 maintenance_manager.cc:419] P a885aee58dfe45f2a943e6a846077a98: Scheduling UndoDeltaBlockGCOp(6482c0062489402e9bd0a263e9265934): 448 bytes on disk
I20260812 06:16:58.450184 32065 maintenance_manager.cc:643] P a885aee58dfe45f2a943e6a846077a98: UndoDeltaBlockGCOp(6482c0062489402e9bd0a263e9265934) 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:16:58.450816 32174 maintenance_manager.cc:419] P a885aee58dfe45f2a943e6a846077a98: Scheduling FlushDeltaMemStoresOp(6482c0062489402e9bd0a263e9265934): perf score=2.188937
I20260812 06:16:58.466471 32065 maintenance_manager.cc:643] P a885aee58dfe45f2a943e6a846077a98: FlushDeltaMemStoresOp(6482c0062489402e9bd0a263e9265934) complete. Timing: real 0.015s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4225735,"delete_count":0,"lbm_write_time_us":4729,"lbm_writes_lt_1ms":106,"reinsert_count":0,"update_count":515}
I20260812 06:16:58.467056 32174 maintenance_manager.cc:419] P a885aee58dfe45f2a943e6a846077a98: Scheduling LogGCOp(6482c0062489402e9bd0a263e9265934): free 11564893 bytes of WAL
I20260812 06:16:58.467284 32065 log_reader.cc:385] T 6482c0062489402e9bd0a263e9265934: removed 1 log segments from log reader
I20260812 06:16:58.467355 32065 log.cc:1079] T 6482c0062489402e9bd0a263e9265934 P a885aee58dfe45f2a943e6a846077a98: Deleting log segment in path: /tmp/dist-test-taskgy2iKv/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515407455541-31521-0/minicluster-data/ts-0-root/wals/6482c0062489402e9bd0a263e9265934/wal-000000037 (ops 177-180)
I20260812 06:16:58.469769 32065 maintenance_manager.cc:643] P a885aee58dfe45f2a943e6a846077a98: LogGCOp(6482c0062489402e9bd0a263e9265934) complete. Timing: real 0.003s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:16:58.470136 32174 maintenance_manager.cc:419] P a885aee58dfe45f2a943e6a846077a98: Scheduling FlushDeltaMemStoresOp(6482c0062489402e9bd0a263e9265934): perf score=2.188937
I20260812 06:16:58.481551 32065 maintenance_manager.cc:643] P a885aee58dfe45f2a943e6a846077a98: FlushDeltaMemStoresOp(6482c0062489402e9bd0a263e9265934) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3979584,"delete_count":0,"lbm_write_time_us":3920,"lbm_writes_lt_1ms":100,"reinsert_count":0,"update_count":485}
I20260812 06:16:58.482116 32174 maintenance_manager.cc:419] P a885aee58dfe45f2a943e6a846077a98: Scheduling MajorDeltaCompactionOp(6482c0062489402e9bd0a263e9265934): perf score=1.000000
I20260812 06:16:58.710304 32065 maintenance_manager.cc:643] P a885aee58dfe45f2a943e6a846077a98: MajorDeltaCompactionOp(6482c0062489402e9bd0a263e9265934) complete. Timing: real 0.228s	user 0.165s	sys 0.057s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979751,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":224,"lbm_read_time_us":14808,"lbm_reads_lt_1ms":774,"lbm_write_time_us":41319,"lbm_writes_lt_1ms":743,"mutex_wait_us":57,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":28800,"thread_start_us":77,"threads_started":1,"update_count":3500}
I20260812 06:16:58.710850 32174 maintenance_manager.cc:419] P a885aee58dfe45f2a943e6a846077a98: Scheduling FlushDeltaMemStoresOp(6482c0062489402e9bd0a263e9265934): perf score=18.063937
I20260812 06:16:58.777421 32065 maintenance_manager.cc:643] P a885aee58dfe45f2a943e6a846077a98: FlushDeltaMemStoresOp(6482c0062489402e9bd0a263e9265934) complete. Timing: real 0.066s	user 0.043s	sys 0.020s Metrics: {"bytes_written":20512320,"delete_count":0,"lbm_write_time_us":29566,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:16:58.778074 32174 maintenance_manager.cc:419] P a885aee58dfe45f2a943e6a846077a98: Scheduling FlushDeltaMemStoresOp(6482c0062489402e9bd0a263e9265934): perf score=2.188937
I20260812 06:16:58.794638 32065 maintenance_manager.cc:643] P a885aee58dfe45f2a943e6a846077a98: FlushDeltaMemStoresOp(6482c0062489402e9bd0a263e9265934) complete. Timing: real 0.016s	user 0.007s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6854,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:58.795107 32174 maintenance_manager.cc:419] P a885aee58dfe45f2a943e6a846077a98: Scheduling MajorDeltaCompactionOp(6482c0062489402e9bd0a263e9265934): perf score=1.000000
I20260812 06:16:58.951133 31521 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.226s	user 1.872s	sys 0.195s
I20260812 06:16:58.958400 32065 maintenance_manager.cc:643] P a885aee58dfe45f2a943e6a846077a98: MajorDeltaCompactionOp(6482c0062489402e9bd0a263e9265934) complete. Timing: real 0.163s	user 0.135s	sys 0.028s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877107,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"lbm_read_time_us":11717,"lbm_reads_lt_1ms":660,"lbm_write_time_us":33951,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1920,"update_count":3000}
I20260812 06:16:58.958925 32174 maintenance_manager.cc:419] P a885aee58dfe45f2a943e6a846077a98: Scheduling FlushDeltaMemStoresOp(6482c0062489402e9bd0a263e9265934): perf score=14.095187
I20260812 06:16:58.992103 32065 maintenance_manager.cc:643] P a885aee58dfe45f2a943e6a846077a98: FlushDeltaMemStoresOp(6482c0062489402e9bd0a263e9265934) complete. Timing: real 0.033s	user 0.020s	sys 0.011s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":16070,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2000}
I20260812 06:16:58.992624 32174 maintenance_manager.cc:419] P a885aee58dfe45f2a943e6a846077a98: Scheduling MajorDeltaCompactionOp(6482c0062489402e9bd0a263e9265934): perf score=1.000000
I20260812 06:16:59.024098 31521 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.072s	user 0.001s	sys 0.000s
I20260812 06:16:59.024837 31521 tablet_server.cc:179] TabletServer@127.30.200.65:0 shutting down...
I20260812 06:16:59.145569 32065 maintenance_manager.cc:643] P a885aee58dfe45f2a943e6a846077a98: MajorDeltaCompactionOp(6482c0062489402e9bd0a263e9265934) complete. Timing: real 0.153s	user 0.095s	sys 0.036s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672157,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":256,"lbm_read_time_us":8885,"lbm_reads_lt_1ms":467,"lbm_write_time_us":30277,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":442,"mutex_wait_us":66,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:16:59.146608 31521 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:16:59.147049 31521 tablet_replica.cc:333] T 6482c0062489402e9bd0a263e9265934 P a885aee58dfe45f2a943e6a846077a98: stopping tablet replica
I20260812 06:16:59.147238 31521 raft_consensus.cc:2243] T 6482c0062489402e9bd0a263e9265934 P a885aee58dfe45f2a943e6a846077a98 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:59.147461 31521 raft_consensus.cc:2272] T 6482c0062489402e9bd0a263e9265934 P a885aee58dfe45f2a943e6a846077a98 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:59.151502 31521 tablet_server.cc:196] TabletServer@127.30.200.65:0 shutdown complete.
I20260812 06:16:59.335988 31521 master.cc:562] Master@127.30.200.126:38439 shutting down...
I20260812 06:16:59.340487 31521 raft_consensus.cc:2243] T 00000000000000000000000000000000 P c4bb42fa541844c4a3d97b3a0b47a429 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:59.340756 31521 raft_consensus.cc:2272] T 00000000000000000000000000000000 P c4bb42fa541844c4a3d97b3a0b47a429 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:59.340876 31521 tablet_replica.cc:333] T 00000000000000000000000000000000 P c4bb42fa541844c4a3d97b3a0b47a429: stopping tablet replica
I20260812 06:16:59.354161 31521 master.cc:584] Master@127.30.200.126:38439 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (6032 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (12004 ms total)

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