[==========] 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:19:26.036682 27206 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.26.145.190:36043
I20260812 06:19:26.037699 27206 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:19:26.038297 27206 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:26.045512 27218 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:19:26.045696 27215 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:19:26.045918 27206 server_base.cc:1061] running on GCE node
W20260812 06:19:26.045989 27216 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:19:26.046619 27206 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:26.046772 27206 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:19:26.046833 27206 hybrid_clock.cc:648] HybridClock initialized: now 1786515566046830 us; error 0 us; skew 500 ppm
I20260812 06:19:26.048743 27206 webserver.cc:533] Webserver started at http://127.26.145.190:45253/ using document root <none> and password file <none>
I20260812 06:19:26.049321 27206 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:26.049420 27206 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:26.049683 27206 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:26.051775 27206 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566024816-27206-0/minicluster-data/master-0-root/instance:
uuid: "d0371c7e27a34c5087517274770817cc"
format_stamp: "Formatted at 2026-08-12 06:19:26 on dist-test-slave-h6n0"
I20260812 06:19:26.055222 27206 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.004s	sys 0.000s
I20260812 06:19:26.057307 27225 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:19:26.058650 27206 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:19:26.058799 27206 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566024816-27206-0/minicluster-data/master-0-root
uuid: "d0371c7e27a34c5087517274770817cc"
format_stamp: "Formatted at 2026-08-12 06:19:26 on dist-test-slave-h6n0"
I20260812 06:19:26.058916 27206 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566024816-27206-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566024816-27206-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566024816-27206-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:19:26.100188 27206 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:26.100945 27206 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:19:26.101166 27206 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:26.110105 27206 rpc_server.cc:307] RPC server started. Bound to: 127.26.145.190:36043
I20260812 06:19:26.110219 27322 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.26.145.190:36043 every 8 connection(s)
I20260812 06:19:26.112897 27324 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:19:26.118692 27324 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P d0371c7e27a34c5087517274770817cc: Bootstrap starting.
I20260812 06:19:26.121210 27324 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P d0371c7e27a34c5087517274770817cc: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:26.122134 27324 log.cc:826] T 00000000000000000000000000000000 P d0371c7e27a34c5087517274770817cc: Log is configured to *not* fsync() on all Append() calls
I20260812 06:19:26.124826 27324 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P d0371c7e27a34c5087517274770817cc: No bootstrap required, opened a new log
I20260812 06:19:26.128885 27324 raft_consensus.cc:359] T 00000000000000000000000000000000 P d0371c7e27a34c5087517274770817cc [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d0371c7e27a34c5087517274770817cc" member_type: VOTER }
I20260812 06:19:26.129098 27324 raft_consensus.cc:385] T 00000000000000000000000000000000 P d0371c7e27a34c5087517274770817cc [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:26.129148 27324 raft_consensus.cc:740] T 00000000000000000000000000000000 P d0371c7e27a34c5087517274770817cc [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: d0371c7e27a34c5087517274770817cc, State: Initialized, Role: FOLLOWER
I20260812 06:19:26.129894 27324 consensus_queue.cc:260] T 00000000000000000000000000000000 P d0371c7e27a34c5087517274770817cc [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: "d0371c7e27a34c5087517274770817cc" member_type: VOTER }
I20260812 06:19:26.130053 27324 raft_consensus.cc:399] T 00000000000000000000000000000000 P d0371c7e27a34c5087517274770817cc [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:26.130107 27324 raft_consensus.cc:493] T 00000000000000000000000000000000 P d0371c7e27a34c5087517274770817cc [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:26.130213 27324 raft_consensus.cc:3060] T 00000000000000000000000000000000 P d0371c7e27a34c5087517274770817cc [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:26.131177 27324 raft_consensus.cc:515] T 00000000000000000000000000000000 P d0371c7e27a34c5087517274770817cc [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d0371c7e27a34c5087517274770817cc" member_type: VOTER }
I20260812 06:19:26.131603 27324 leader_election.cc:304] T 00000000000000000000000000000000 P d0371c7e27a34c5087517274770817cc [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: d0371c7e27a34c5087517274770817cc; no voters: 
I20260812 06:19:26.131883 27324 leader_election.cc:290] T 00000000000000000000000000000000 P d0371c7e27a34c5087517274770817cc [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:26.132143 27328 raft_consensus.cc:2804] T 00000000000000000000000000000000 P d0371c7e27a34c5087517274770817cc [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:26.132378 27328 raft_consensus.cc:697] T 00000000000000000000000000000000 P d0371c7e27a34c5087517274770817cc [term 1 LEADER]: Becoming Leader. State: Replica: d0371c7e27a34c5087517274770817cc, State: Running, Role: LEADER
I20260812 06:19:26.132836 27328 consensus_queue.cc:237] T 00000000000000000000000000000000 P d0371c7e27a34c5087517274770817cc [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: "d0371c7e27a34c5087517274770817cc" member_type: VOTER }
I20260812 06:19:26.132899 27324 sys_catalog.cc:565] T 00000000000000000000000000000000 P d0371c7e27a34c5087517274770817cc [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:26.134792 27329 sys_catalog.cc:455] T 00000000000000000000000000000000 P d0371c7e27a34c5087517274770817cc [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "d0371c7e27a34c5087517274770817cc" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d0371c7e27a34c5087517274770817cc" member_type: VOTER } }
I20260812 06:19:26.134936 27329 sys_catalog.cc:458] T 00000000000000000000000000000000 P d0371c7e27a34c5087517274770817cc [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:26.134863 27330 sys_catalog.cc:455] T 00000000000000000000000000000000 P d0371c7e27a34c5087517274770817cc [sys.catalog]: SysCatalogTable state changed. Reason: New leader d0371c7e27a34c5087517274770817cc. Latest consensus state: current_term: 1 leader_uuid: "d0371c7e27a34c5087517274770817cc" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d0371c7e27a34c5087517274770817cc" member_type: VOTER } }
I20260812 06:19:26.135044 27330 sys_catalog.cc:458] T 00000000000000000000000000000000 P d0371c7e27a34c5087517274770817cc [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:26.135407 27206 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:26.135699 27352 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:26.137967 27352 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:26.145761 27352 catalog_manager.cc:1383] Generated new cluster ID: b4e4557bfd5e4c27b92689856a85b5d4
I20260812 06:19:26.145876 27352 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:26.161149 27352 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:26.162427 27352 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:26.173236 27352 catalog_manager.cc:6092] T 00000000000000000000000000000000 P d0371c7e27a34c5087517274770817cc: Generated new TSK 0
I20260812 06:19:26.174022 27352 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:26.200569 27206 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:26.203766 27366 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:19:26.203995 27362 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:19:26.203842 27364 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:19:26.204406 27206 server_base.cc:1061] running on GCE node
I20260812 06:19:26.204734 27206 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:26.204787 27206 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:19:26.204807 27206 hybrid_clock.cc:648] HybridClock initialized: now 1786515566204807 us; error 0 us; skew 500 ppm
I20260812 06:19:26.206465 27206 webserver.cc:533] Webserver started at http://127.26.145.129:41385/ using document root <none> and password file <none>
I20260812 06:19:26.206712 27206 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:26.206765 27206 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:26.206864 27206 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:26.207316 27206 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566024816-27206-0/minicluster-data/ts-0-root/instance:
uuid: "608b5dab79144bc7b88c0ed82eeda305"
format_stamp: "Formatted at 2026-08-12 06:19:26 on dist-test-slave-h6n0"
I20260812 06:19:26.208966 27206 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:26.210026 27373 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:19:26.210304 27206 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:26.210421 27206 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566024816-27206-0/minicluster-data/ts-0-root
uuid: "608b5dab79144bc7b88c0ed82eeda305"
format_stamp: "Formatted at 2026-08-12 06:19:26 on dist-test-slave-h6n0"
I20260812 06:19:26.210512 27206 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566024816-27206-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566024816-27206-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566024816-27206-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:19:26.225301 27206 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:26.225888 27206 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:26.226521 27206 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:26.227516 27206 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:26.227619 27206 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:26.227707 27206 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:26.227762 27206 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:26.235772 27206 rpc_server.cc:307] RPC server started. Bound to: 127.26.145.129:44621
I20260812 06:19:26.235826 27499 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.26.145.129:44621 every 8 connection(s)
I20260812 06:19:26.251374 27501 heartbeater.cc:344] Connected to a master server at 127.26.145.190:36043
I20260812 06:19:26.251669 27501 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:26.252238 27501 heartbeater.cc:507] Master 127.26.145.190:36043 requested a full tablet report, sending...
I20260812 06:19:26.254244 27263 ts_manager.cc:194] Registered new tserver with Master: 608b5dab79144bc7b88c0ed82eeda305 (127.26.145.129:44621)
I20260812 06:19:26.255172 27206 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.018589025s
I20260812 06:19:26.255957 27263 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:35954
I20260812 06:19:26.268718 27263 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:35966:
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:19:26.288368 27438 tablet_service.cc:1511] Processing CreateTablet for tablet a266596c4fb048edbe25f4c77cb4d2bd (DEFAULT_TABLE table=heavy-update-compaction-test [id=9ac2487f970b42acb98e77244eb5b216]), partition=
I20260812 06:19:26.288923 27438 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet a266596c4fb048edbe25f4c77cb4d2bd. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:26.291857 27521 tablet_bootstrap.cc:492] T a266596c4fb048edbe25f4c77cb4d2bd P 608b5dab79144bc7b88c0ed82eeda305: Bootstrap starting.
I20260812 06:19:26.292941 27521 tablet_bootstrap.cc:654] T a266596c4fb048edbe25f4c77cb4d2bd P 608b5dab79144bc7b88c0ed82eeda305: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:26.294623 27521 tablet_bootstrap.cc:492] T a266596c4fb048edbe25f4c77cb4d2bd P 608b5dab79144bc7b88c0ed82eeda305: No bootstrap required, opened a new log
I20260812 06:19:26.294732 27521 ts_tablet_manager.cc:1403] T a266596c4fb048edbe25f4c77cb4d2bd P 608b5dab79144bc7b88c0ed82eeda305: Time spent bootstrapping tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:19:26.295274 27521 raft_consensus.cc:359] T a266596c4fb048edbe25f4c77cb4d2bd P 608b5dab79144bc7b88c0ed82eeda305 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "608b5dab79144bc7b88c0ed82eeda305" member_type: VOTER last_known_addr { host: "127.26.145.129" port: 44621 } }
I20260812 06:19:26.295403 27521 raft_consensus.cc:385] T a266596c4fb048edbe25f4c77cb4d2bd P 608b5dab79144bc7b88c0ed82eeda305 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:26.295441 27521 raft_consensus.cc:740] T a266596c4fb048edbe25f4c77cb4d2bd P 608b5dab79144bc7b88c0ed82eeda305 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 608b5dab79144bc7b88c0ed82eeda305, State: Initialized, Role: FOLLOWER
I20260812 06:19:26.295581 27521 consensus_queue.cc:260] T a266596c4fb048edbe25f4c77cb4d2bd P 608b5dab79144bc7b88c0ed82eeda305 [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: "608b5dab79144bc7b88c0ed82eeda305" member_type: VOTER last_known_addr { host: "127.26.145.129" port: 44621 } }
I20260812 06:19:26.295677 27521 raft_consensus.cc:399] T a266596c4fb048edbe25f4c77cb4d2bd P 608b5dab79144bc7b88c0ed82eeda305 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:26.295714 27521 raft_consensus.cc:493] T a266596c4fb048edbe25f4c77cb4d2bd P 608b5dab79144bc7b88c0ed82eeda305 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:26.295766 27521 raft_consensus.cc:3060] T a266596c4fb048edbe25f4c77cb4d2bd P 608b5dab79144bc7b88c0ed82eeda305 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:26.296794 27521 raft_consensus.cc:515] T a266596c4fb048edbe25f4c77cb4d2bd P 608b5dab79144bc7b88c0ed82eeda305 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "608b5dab79144bc7b88c0ed82eeda305" member_type: VOTER last_known_addr { host: "127.26.145.129" port: 44621 } }
I20260812 06:19:26.296947 27521 leader_election.cc:304] T a266596c4fb048edbe25f4c77cb4d2bd P 608b5dab79144bc7b88c0ed82eeda305 [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: 608b5dab79144bc7b88c0ed82eeda305; no voters: 
I20260812 06:19:26.297159 27521 leader_election.cc:290] T a266596c4fb048edbe25f4c77cb4d2bd P 608b5dab79144bc7b88c0ed82eeda305 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:26.297401 27525 raft_consensus.cc:2804] T a266596c4fb048edbe25f4c77cb4d2bd P 608b5dab79144bc7b88c0ed82eeda305 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:26.297498 27521 ts_tablet_manager.cc:1434] T a266596c4fb048edbe25f4c77cb4d2bd P 608b5dab79144bc7b88c0ed82eeda305: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:19:26.297676 27525 raft_consensus.cc:697] T a266596c4fb048edbe25f4c77cb4d2bd P 608b5dab79144bc7b88c0ed82eeda305 [term 1 LEADER]: Becoming Leader. State: Replica: 608b5dab79144bc7b88c0ed82eeda305, State: Running, Role: LEADER
I20260812 06:19:26.297832 27525 consensus_queue.cc:237] T a266596c4fb048edbe25f4c77cb4d2bd P 608b5dab79144bc7b88c0ed82eeda305 [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: "608b5dab79144bc7b88c0ed82eeda305" member_type: VOTER last_known_addr { host: "127.26.145.129" port: 44621 } }
I20260812 06:19:26.298040 27501 heartbeater.cc:499] Master 127.26.145.190:36043 was elected leader, sending a full tablet report...
I20260812 06:19:26.300660 27263 catalog_manager.cc:5719] T a266596c4fb048edbe25f4c77cb4d2bd P 608b5dab79144bc7b88c0ed82eeda305 reported cstate change: term changed from 0 to 1, leader changed from <none> to 608b5dab79144bc7b88c0ed82eeda305 (127.26.145.129). New cstate: current_term: 1 leader_uuid: "608b5dab79144bc7b88c0ed82eeda305" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "608b5dab79144bc7b88c0ed82eeda305" member_type: VOTER last_known_addr { host: "127.26.145.129" port: 44621 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:26.371932 27206 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.065s	user 0.020s	sys 0.008s
I20260812 06:19:26.487176 27506 maintenance_manager.cc:419] P 608b5dab79144bc7b88c0ed82eeda305: Scheduling FlushMRSOp(a266596c4fb048edbe25f4c77cb4d2bd): perf score=15.086190
I20260812 06:19:26.680312 27384 maintenance_manager.cc:643] P 608b5dab79144bc7b88c0ed82eeda305: FlushMRSOp(a266596c4fb048edbe25f4c77cb4d2bd) complete. Timing: real 0.193s	user 0.150s	sys 0.028s Metrics: {"bytes_written":12307491,"cfile_init":1,"compiler_manager_pool.queue_time_us":244,"delete_count":0,"dirs.queue_time_us":125,"dirs.run_cpu_time_us":357,"dirs.run_wall_time_us":985,"drs_written":1,"lbm_read_time_us":75,"lbm_reads_lt_1ms":4,"lbm_write_time_us":47285,"lbm_writes_lt_1ms":657,"peak_mem_usage":0,"reinsert_count":0,"rows_written":103,"thread_start_us":139,"threads_started":1,"update_count":1500}
I20260812 06:19:26.681612 27506 maintenance_manager.cc:419] P 608b5dab79144bc7b88c0ed82eeda305: Scheduling LogGCOp(a266596c4fb048edbe25f4c77cb4d2bd): free 8725963 bytes of WAL
I20260812 06:19:26.682047 27384 log_reader.cc:385] T a266596c4fb048edbe25f4c77cb4d2bd: removed 1 log segments from log reader
I20260812 06:19:26.682127 27384 log.cc:1079] T a266596c4fb048edbe25f4c77cb4d2bd P 608b5dab79144bc7b88c0ed82eeda305: Deleting log segment in path: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566024816-27206-0/minicluster-data/ts-0-root/wals/a266596c4fb048edbe25f4c77cb4d2bd/wal-000000001 (ops 1-6)
I20260812 06:19:26.684743 27384 maintenance_manager.cc:643] P 608b5dab79144bc7b88c0ed82eeda305: LogGCOp(a266596c4fb048edbe25f4c77cb4d2bd) complete. Timing: real 0.003s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:19:26.685118 27506 maintenance_manager.cc:419] P 608b5dab79144bc7b88c0ed82eeda305: Scheduling FlushDeltaMemStoresOp(a266596c4fb048edbe25f4c77cb4d2bd): perf score=2.188937
I20260812 06:19:26.706609 27384 maintenance_manager.cc:643] P 608b5dab79144bc7b88c0ed82eeda305: FlushDeltaMemStoresOp(a266596c4fb048edbe25f4c77cb4d2bd) complete. Timing: real 0.021s	user 0.013s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":8543,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:26.707194 27506 maintenance_manager.cc:419] P 608b5dab79144bc7b88c0ed82eeda305: Scheduling UndoDeltaBlockGCOp(a266596c4fb048edbe25f4c77cb4d2bd): 12308958 bytes on disk
I20260812 06:19:26.708005 27384 maintenance_manager.cc:643] P 608b5dab79144bc7b88c0ed82eeda305: UndoDeltaBlockGCOp(a266596c4fb048edbe25f4c77cb4d2bd) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":99,"lbm_reads_lt_1ms":4}
I20260812 06:19:26.708526 27506 maintenance_manager.cc:419] P 608b5dab79144bc7b88c0ed82eeda305: Scheduling MajorDeltaCompactionOp(a266596c4fb048edbe25f4c77cb4d2bd): perf score=1.000000
I20260812 06:19:26.837579 27384 maintenance_manager.cc:643] P 608b5dab79144bc7b88c0ed82eeda305: MajorDeltaCompactionOp(a266596c4fb048edbe25f4c77cb4d2bd) complete. Timing: real 0.129s	user 0.092s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631313,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":902,"lbm_read_time_us":8254,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24319,"lbm_writes_lt_1ms":443,"mutex_wait_us":29,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":14464,"thread_start_us":375,"threads_started":5,"update_count":2000}
I20260812 06:19:26.838792 27506 maintenance_manager.cc:419] P 608b5dab79144bc7b88c0ed82eeda305: Scheduling FlushDeltaMemStoresOp(a266596c4fb048edbe25f4c77cb4d2bd): perf score=10.126437
I20260812 06:19:26.891681 27384 maintenance_manager.cc:643] P 608b5dab79144bc7b88c0ed82eeda305: FlushDeltaMemStoresOp(a266596c4fb048edbe25f4c77cb4d2bd) complete. Timing: real 0.052s	user 0.018s	sys 0.028s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":21006,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:26.892481 27506 maintenance_manager.cc:419] P 608b5dab79144bc7b88c0ed82eeda305: Scheduling FlushDeltaMemStoresOp(a266596c4fb048edbe25f4c77cb4d2bd): perf score=2.188937
I20260812 06:19:26.904529 27384 maintenance_manager.cc:643] P 608b5dab79144bc7b88c0ed82eeda305: FlushDeltaMemStoresOp(a266596c4fb048edbe25f4c77cb4d2bd) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4145,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:26.905145 27506 maintenance_manager.cc:419] P 608b5dab79144bc7b88c0ed82eeda305: Scheduling MajorDeltaCompactionOp(a266596c4fb048edbe25f4c77cb4d2bd): perf score=1.000000
I20260812 06:19:27.034300 27384 maintenance_manager.cc:643] P 608b5dab79144bc7b88c0ed82eeda305: MajorDeltaCompactionOp(a266596c4fb048edbe25f4c77cb4d2bd) complete. Timing: real 0.129s	user 0.098s	sys 0.028s 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":493,"lbm_read_time_us":9271,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25670,"lbm_writes_lt_1ms":443,"mutex_wait_us":67,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:27.035028 27506 maintenance_manager.cc:419] P 608b5dab79144bc7b88c0ed82eeda305: Scheduling FlushDeltaMemStoresOp(a266596c4fb048edbe25f4c77cb4d2bd): perf score=10.126437
I20260812 06:19:27.087369 27384 maintenance_manager.cc:643] P 608b5dab79144bc7b88c0ed82eeda305: FlushDeltaMemStoresOp(a266596c4fb048edbe25f4c77cb4d2bd) complete. Timing: real 0.052s	user 0.029s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16374,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:27.087986 27506 maintenance_manager.cc:419] P 608b5dab79144bc7b88c0ed82eeda305: Scheduling FlushDeltaMemStoresOp(a266596c4fb048edbe25f4c77cb4d2bd): perf score=2.188937
I20260812 06:19:27.102856 27384 maintenance_manager.cc:643] P 608b5dab79144bc7b88c0ed82eeda305: FlushDeltaMemStoresOp(a266596c4fb048edbe25f4c77cb4d2bd) complete. Timing: real 0.015s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5377,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:27.103572 27506 maintenance_manager.cc:419] P 608b5dab79144bc7b88c0ed82eeda305: Scheduling MajorDeltaCompactionOp(a266596c4fb048edbe25f4c77cb4d2bd): perf score=1.000000
I20260812 06:19:27.248247 27384 maintenance_manager.cc:643] P 608b5dab79144bc7b88c0ed82eeda305: MajorDeltaCompactionOp(a266596c4fb048edbe25f4c77cb4d2bd) complete. Timing: real 0.144s	user 0.108s	sys 0.036s 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":184,"lbm_read_time_us":8948,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28495,"lbm_writes_lt_1ms":443,"mutex_wait_us":69,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8320,"update_count":2000}
I20260812 06:19:27.248888 27506 maintenance_manager.cc:419] P 608b5dab79144bc7b88c0ed82eeda305: Scheduling FlushDeltaMemStoresOp(a266596c4fb048edbe25f4c77cb4d2bd): perf score=11.118625
I20260812 06:19:27.296103 27384 maintenance_manager.cc:643] P 608b5dab79144bc7b88c0ed82eeda305: FlushDeltaMemStoresOp(a266596c4fb048edbe25f4c77cb4d2bd) complete. Timing: real 0.047s	user 0.034s	sys 0.011s Metrics: {"bytes_written":12553636,"delete_count":0,"lbm_write_time_us":16932,"lbm_writes_lt_1ms":309,"reinsert_count":0,"update_count":1530}
I20260812 06:19:27.296917 27506 maintenance_manager.cc:419] P 608b5dab79144bc7b88c0ed82eeda305: Scheduling FlushDeltaMemStoresOp(a266596c4fb048edbe25f4c77cb4d2bd): perf score=2.188937
I20260812 06:19:27.317313 27384 maintenance_manager.cc:643] P 608b5dab79144bc7b88c0ed82eeda305: FlushDeltaMemStoresOp(a266596c4fb048edbe25f4c77cb4d2bd) complete. Timing: real 0.020s	user 0.013s	sys 0.004s Metrics: {"bytes_written":3856509,"delete_count":0,"lbm_write_time_us":7098,"lbm_writes_lt_1ms":97,"reinsert_count":0,"update_count":470}
I20260812 06:19:27.317951 27506 maintenance_manager.cc:419] P 608b5dab79144bc7b88c0ed82eeda305: Scheduling MajorDeltaCompactionOp(a266596c4fb048edbe25f4c77cb4d2bd): perf score=1.000000
I20260812 06:19:27.486754 27384 maintenance_manager.cc:643] P 608b5dab79144bc7b88c0ed82eeda305: MajorDeltaCompactionOp(a266596c4fb048edbe25f4c77cb4d2bd) complete. Timing: real 0.169s	user 0.113s	sys 0.052s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631308,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":971,"lbm_read_time_us":11983,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28444,"lbm_writes_lt_1ms":443,"mutex_wait_us":364,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10752,"update_count":2000}
I20260812 06:19:27.489044 27506 maintenance_manager.cc:419] P 608b5dab79144bc7b88c0ed82eeda305: Scheduling FlushDeltaMemStoresOp(a266596c4fb048edbe25f4c77cb4d2bd): perf score=10.126437
I20260812 06:19:27.532372 27384 maintenance_manager.cc:643] P 608b5dab79144bc7b88c0ed82eeda305: FlushDeltaMemStoresOp(a266596c4fb048edbe25f4c77cb4d2bd) complete. Timing: real 0.043s	user 0.021s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17909,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:27.533049 27506 maintenance_manager.cc:419] P 608b5dab79144bc7b88c0ed82eeda305: Scheduling FlushDeltaMemStoresOp(a266596c4fb048edbe25f4c77cb4d2bd): perf score=2.188937
I20260812 06:19:27.549508 27384 maintenance_manager.cc:643] P 608b5dab79144bc7b88c0ed82eeda305: FlushDeltaMemStoresOp(a266596c4fb048edbe25f4c77cb4d2bd) complete. Timing: real 0.016s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5728,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:27.550092 27506 maintenance_manager.cc:419] P 608b5dab79144bc7b88c0ed82eeda305: Scheduling MajorDeltaCompactionOp(a266596c4fb048edbe25f4c77cb4d2bd): perf score=1.000000
I20260812 06:19:27.685734 27384 maintenance_manager.cc:643] P 608b5dab79144bc7b88c0ed82eeda305: MajorDeltaCompactionOp(a266596c4fb048edbe25f4c77cb4d2bd) complete. Timing: real 0.135s	user 0.107s	sys 0.028s 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":346,"lbm_read_time_us":8711,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27088,"lbm_writes_lt_1ms":443,"mutex_wait_us":65,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":28928,"update_count":2000}
I20260812 06:19:27.686869 27506 maintenance_manager.cc:419] P 608b5dab79144bc7b88c0ed82eeda305: Scheduling FlushDeltaMemStoresOp(a266596c4fb048edbe25f4c77cb4d2bd): perf score=10.126437
I20260812 06:19:27.733594 27384 maintenance_manager.cc:643] P 608b5dab79144bc7b88c0ed82eeda305: FlushDeltaMemStoresOp(a266596c4fb048edbe25f4c77cb4d2bd) complete. Timing: real 0.047s	user 0.030s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18672,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:27.734196 27506 maintenance_manager.cc:419] P 608b5dab79144bc7b88c0ed82eeda305: Scheduling FlushDeltaMemStoresOp(a266596c4fb048edbe25f4c77cb4d2bd): perf score=2.188937
I20260812 06:19:27.747787 27384 maintenance_manager.cc:643] P 608b5dab79144bc7b88c0ed82eeda305: FlushDeltaMemStoresOp(a266596c4fb048edbe25f4c77cb4d2bd) complete. Timing: real 0.013s	user 0.009s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4754,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:27.748790 27506 maintenance_manager.cc:419] P 608b5dab79144bc7b88c0ed82eeda305: Scheduling MajorDeltaCompactionOp(a266596c4fb048edbe25f4c77cb4d2bd): perf score=1.000000
I20260812 06:19:27.888175 27384 maintenance_manager.cc:643] P 608b5dab79144bc7b88c0ed82eeda305: MajorDeltaCompactionOp(a266596c4fb048edbe25f4c77cb4d2bd) complete. Timing: real 0.139s	user 0.106s	sys 0.030s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1009,"lbm_read_time_us":10176,"lbm_reads_lt_1ms":468,"lbm_write_time_us":28450,"lbm_writes_lt_1ms":443,"mutex_wait_us":51,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11264,"update_count":2000}
I20260812 06:19:27.888736 27506 maintenance_manager.cc:419] P 608b5dab79144bc7b88c0ed82eeda305: Scheduling FlushDeltaMemStoresOp(a266596c4fb048edbe25f4c77cb4d2bd): perf score=10.126437
I20260812 06:19:27.927140 27384 maintenance_manager.cc:643] P 608b5dab79144bc7b88c0ed82eeda305: FlushDeltaMemStoresOp(a266596c4fb048edbe25f4c77cb4d2bd) complete. Timing: real 0.038s	user 0.024s	sys 0.013s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15867,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:27.927654 27506 maintenance_manager.cc:419] P 608b5dab79144bc7b88c0ed82eeda305: Scheduling FlushMRSOp(a266596c4fb048edbe25f4c77cb4d2bd): perf score=1.000000
I20260812 06:19:27.970357 27384 maintenance_manager.cc:643] P 608b5dab79144bc7b88c0ed82eeda305: FlushMRSOp(a266596c4fb048edbe25f4c77cb4d2bd) complete. Timing: real 0.043s	user 0.023s	sys 0.004s Metrics: {"bytes_written":1152509,"cfile_init":1,"dirs.queue_time_us":55,"dirs.run_cpu_time_us":212,"dirs.run_wall_time_us":1285,"drs_written":1,"lbm_read_time_us":46,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1677,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:19:27.972158 27506 maintenance_manager.cc:419] P 608b5dab79144bc7b88c0ed82eeda305: Scheduling UndoDeltaBlockGCOp(a266596c4fb048edbe25f4c77cb4d2bd): 447 bytes on disk
I20260812 06:19:27.973053 27384 maintenance_manager.cc:643] P 608b5dab79144bc7b88c0ed82eeda305: UndoDeltaBlockGCOp(a266596c4fb048edbe25f4c77cb4d2bd) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":176,"lbm_reads_lt_1ms":4}
I20260812 06:19:27.973590 27506 maintenance_manager.cc:419] P 608b5dab79144bc7b88c0ed82eeda305: Scheduling FlushDeltaMemStoresOp(a266596c4fb048edbe25f4c77cb4d2bd): perf score=3.181125
I20260812 06:19:27.985193 27384 maintenance_manager.cc:643] P 608b5dab79144bc7b88c0ed82eeda305: FlushDeltaMemStoresOp(a266596c4fb048edbe25f4c77cb4d2bd) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4512901,"delete_count":0,"lbm_write_time_us":4324,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:27.985738 27506 maintenance_manager.cc:419] P 608b5dab79144bc7b88c0ed82eeda305: Scheduling LogGCOp(a266596c4fb048edbe25f4c77cb4d2bd): free 120553377 bytes of WAL
I20260812 06:19:27.986011 27384 log_reader.cc:385] T a266596c4fb048edbe25f4c77cb4d2bd: removed 12 log segments from log reader
I20260812 06:19:27.986092 27384 log.cc:1079] T a266596c4fb048edbe25f4c77cb4d2bd P 608b5dab79144bc7b88c0ed82eeda305: Deleting log segment in path: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566024816-27206-0/minicluster-data/ts-0-root/wals/a266596c4fb048edbe25f4c77cb4d2bd/wal-000000002 (ops 7-11)
I20260812 06:19:27.986150 27384 log.cc:1079] T a266596c4fb048edbe25f4c77cb4d2bd P 608b5dab79144bc7b88c0ed82eeda305: Deleting log segment in path: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566024816-27206-0/minicluster-data/ts-0-root/wals/a266596c4fb048edbe25f4c77cb4d2bd/wal-000000003 (ops 12-16)
I20260812 06:19:27.986212 27384 log.cc:1079] T a266596c4fb048edbe25f4c77cb4d2bd P 608b5dab79144bc7b88c0ed82eeda305: Deleting log segment in path: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566024816-27206-0/minicluster-data/ts-0-root/wals/a266596c4fb048edbe25f4c77cb4d2bd/wal-000000004 (ops 17-21)
I20260812 06:19:27.986255 27384 log.cc:1079] T a266596c4fb048edbe25f4c77cb4d2bd P 608b5dab79144bc7b88c0ed82eeda305: Deleting log segment in path: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566024816-27206-0/minicluster-data/ts-0-root/wals/a266596c4fb048edbe25f4c77cb4d2bd/wal-000000005 (ops 22-26)
I20260812 06:19:27.986295 27384 log.cc:1079] T a266596c4fb048edbe25f4c77cb4d2bd P 608b5dab79144bc7b88c0ed82eeda305: Deleting log segment in path: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566024816-27206-0/minicluster-data/ts-0-root/wals/a266596c4fb048edbe25f4c77cb4d2bd/wal-000000006 (ops 27-30)
I20260812 06:19:27.986334 27384 log.cc:1079] T a266596c4fb048edbe25f4c77cb4d2bd P 608b5dab79144bc7b88c0ed82eeda305: Deleting log segment in path: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566024816-27206-0/minicluster-data/ts-0-root/wals/a266596c4fb048edbe25f4c77cb4d2bd/wal-000000007 (ops 31-35)
I20260812 06:19:27.986373 27384 log.cc:1079] T a266596c4fb048edbe25f4c77cb4d2bd P 608b5dab79144bc7b88c0ed82eeda305: Deleting log segment in path: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566024816-27206-0/minicluster-data/ts-0-root/wals/a266596c4fb048edbe25f4c77cb4d2bd/wal-000000008 (ops 36-40)
I20260812 06:19:27.986414 27384 log.cc:1079] T a266596c4fb048edbe25f4c77cb4d2bd P 608b5dab79144bc7b88c0ed82eeda305: Deleting log segment in path: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566024816-27206-0/minicluster-data/ts-0-root/wals/a266596c4fb048edbe25f4c77cb4d2bd/wal-000000009 (ops 41-44)
I20260812 06:19:27.986457 27384 log.cc:1079] T a266596c4fb048edbe25f4c77cb4d2bd P 608b5dab79144bc7b88c0ed82eeda305: Deleting log segment in path: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566024816-27206-0/minicluster-data/ts-0-root/wals/a266596c4fb048edbe25f4c77cb4d2bd/wal-000000010 (ops 45-49)
I20260812 06:19:27.986495 27384 log.cc:1079] T a266596c4fb048edbe25f4c77cb4d2bd P 608b5dab79144bc7b88c0ed82eeda305: Deleting log segment in path: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566024816-27206-0/minicluster-data/ts-0-root/wals/a266596c4fb048edbe25f4c77cb4d2bd/wal-000000011 (ops 50-54)
I20260812 06:19:27.986582 27384 log.cc:1079] T a266596c4fb048edbe25f4c77cb4d2bd P 608b5dab79144bc7b88c0ed82eeda305: Deleting log segment in path: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566024816-27206-0/minicluster-data/ts-0-root/wals/a266596c4fb048edbe25f4c77cb4d2bd/wal-000000012 (ops 55-59)
I20260812 06:19:27.986647 27384 log.cc:1079] T a266596c4fb048edbe25f4c77cb4d2bd P 608b5dab79144bc7b88c0ed82eeda305: Deleting log segment in path: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566024816-27206-0/minicluster-data/ts-0-root/wals/a266596c4fb048edbe25f4c77cb4d2bd/wal-000000013 (ops 60-64)
I20260812 06:19:28.013888 27384 maintenance_manager.cc:643] P 608b5dab79144bc7b88c0ed82eeda305: LogGCOp(a266596c4fb048edbe25f4c77cb4d2bd) complete. Timing: real 0.028s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:19:28.014464 27506 maintenance_manager.cc:419] P 608b5dab79144bc7b88c0ed82eeda305: Scheduling FlushDeltaMemStoresOp(a266596c4fb048edbe25f4c77cb4d2bd): perf score=2.188937
I20260812 06:19:28.031872 27384 maintenance_manager.cc:643] P 608b5dab79144bc7b88c0ed82eeda305: FlushDeltaMemStoresOp(a266596c4fb048edbe25f4c77cb4d2bd) complete. Timing: real 0.017s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4574,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:28.032423 27506 maintenance_manager.cc:419] P 608b5dab79144bc7b88c0ed82eeda305: Scheduling FlushDeltaMemStoresOp(a266596c4fb048edbe25f4c77cb4d2bd): perf score=2.188937
I20260812 06:19:28.047382 27384 maintenance_manager.cc:643] P 608b5dab79144bc7b88c0ed82eeda305: FlushDeltaMemStoresOp(a266596c4fb048edbe25f4c77cb4d2bd) complete. Timing: real 0.015s	user 0.006s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5725,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:28.047932 27506 maintenance_manager.cc:419] P 608b5dab79144bc7b88c0ed82eeda305: Scheduling MajorDeltaCompactionOp(a266596c4fb048edbe25f4c77cb4d2bd): perf score=1.000000
I20260812 06:19:28.267549 27384 maintenance_manager.cc:643] P 608b5dab79144bc7b88c0ed82eeda305: MajorDeltaCompactionOp(a266596c4fb048edbe25f4c77cb4d2bd) complete. Timing: real 0.219s	user 0.168s	sys 0.048s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836363,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":12100,"lbm_read_time_us":13691,"lbm_reads_lt_1ms":674,"lbm_write_time_us":44501,"lbm_writes_lt_1ms":643,"mutex_wait_us":3023,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2176,"thread_start_us":91,"threads_started":1,"update_count":3000}
I20260812 06:19:28.268283 27506 maintenance_manager.cc:419] P 608b5dab79144bc7b88c0ed82eeda305: Scheduling FlushDeltaMemStoresOp(a266596c4fb048edbe25f4c77cb4d2bd): perf score=14.095187
I20260812 06:19:28.333428 27384 maintenance_manager.cc:643] P 608b5dab79144bc7b88c0ed82eeda305: FlushDeltaMemStoresOp(a266596c4fb048edbe25f4c77cb4d2bd) complete. Timing: real 0.065s	user 0.048s	sys 0.013s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":29751,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:28.334100 27506 maintenance_manager.cc:419] P 608b5dab79144bc7b88c0ed82eeda305: Scheduling FlushDeltaMemStoresOp(a266596c4fb048edbe25f4c77cb4d2bd): perf score=2.188937
I20260812 06:19:28.354152 27384 maintenance_manager.cc:643] P 608b5dab79144bc7b88c0ed82eeda305: FlushDeltaMemStoresOp(a266596c4fb048edbe25f4c77cb4d2bd) complete. Timing: real 0.020s	user 0.008s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":8207,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:28.354699 27506 maintenance_manager.cc:419] P 608b5dab79144bc7b88c0ed82eeda305: Scheduling MajorDeltaCompactionOp(a266596c4fb048edbe25f4c77cb4d2bd): perf score=1.000000
I20260812 06:19:28.544376 27384 maintenance_manager.cc:643] P 608b5dab79144bc7b88c0ed82eeda305: MajorDeltaCompactionOp(a266596c4fb048edbe25f4c77cb4d2bd) complete. Timing: real 0.189s	user 0.120s	sys 0.060s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1678,"lbm_read_time_us":9325,"lbm_reads_lt_1ms":568,"lbm_write_time_us":39438,"lbm_writes_lt_1ms":543,"mutex_wait_us":414,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":37248,"update_count":2500}
I20260812 06:19:28.544986 27506 maintenance_manager.cc:419] P 608b5dab79144bc7b88c0ed82eeda305: Scheduling FlushDeltaMemStoresOp(a266596c4fb048edbe25f4c77cb4d2bd): perf score=14.095187
I20260812 06:19:28.620772 27384 maintenance_manager.cc:643] P 608b5dab79144bc7b88c0ed82eeda305: FlushDeltaMemStoresOp(a266596c4fb048edbe25f4c77cb4d2bd) complete. Timing: real 0.076s	user 0.037s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":28340,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:28.621445 27506 maintenance_manager.cc:419] P 608b5dab79144bc7b88c0ed82eeda305: Scheduling FlushDeltaMemStoresOp(a266596c4fb048edbe25f4c77cb4d2bd): perf score=2.188937
I20260812 06:19:28.637847 27384 maintenance_manager.cc:643] P 608b5dab79144bc7b88c0ed82eeda305: FlushDeltaMemStoresOp(a266596c4fb048edbe25f4c77cb4d2bd) complete. Timing: real 0.016s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5568,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:28.638569 27506 maintenance_manager.cc:419] P 608b5dab79144bc7b88c0ed82eeda305: Scheduling MajorDeltaCompactionOp(a266596c4fb048edbe25f4c77cb4d2bd): perf score=1.000000
I20260812 06:19:28.831391 27384 maintenance_manager.cc:643] P 608b5dab79144bc7b88c0ed82eeda305: MajorDeltaCompactionOp(a266596c4fb048edbe25f4c77cb4d2bd) complete. Timing: real 0.193s	user 0.122s	sys 0.065s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1416,"lbm_read_time_us":11879,"lbm_reads_lt_1ms":564,"lbm_write_time_us":32205,"lbm_writes_lt_1ms":543,"mutex_wait_us":435,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:28.832456 27506 maintenance_manager.cc:419] P 608b5dab79144bc7b88c0ed82eeda305: Scheduling FlushDeltaMemStoresOp(a266596c4fb048edbe25f4c77cb4d2bd): perf score=14.095187
I20260812 06:19:28.903952 27384 maintenance_manager.cc:643] P 608b5dab79144bc7b88c0ed82eeda305: FlushDeltaMemStoresOp(a266596c4fb048edbe25f4c77cb4d2bd) complete. Timing: real 0.071s	user 0.029s	sys 0.035s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":24440,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:28.904524 27506 maintenance_manager.cc:419] P 608b5dab79144bc7b88c0ed82eeda305: Scheduling FlushDeltaMemStoresOp(a266596c4fb048edbe25f4c77cb4d2bd): perf score=2.188937
I20260812 06:19:28.917042 27384 maintenance_manager.cc:643] P 608b5dab79144bc7b88c0ed82eeda305: FlushDeltaMemStoresOp(a266596c4fb048edbe25f4c77cb4d2bd) complete. Timing: real 0.012s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4595,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:28.918008 27506 maintenance_manager.cc:419] P 608b5dab79144bc7b88c0ed82eeda305: Scheduling MajorDeltaCompactionOp(a266596c4fb048edbe25f4c77cb4d2bd): perf score=1.000000
I20260812 06:19:29.105602 27384 maintenance_manager.cc:643] P 608b5dab79144bc7b88c0ed82eeda305: MajorDeltaCompactionOp(a266596c4fb048edbe25f4c77cb4d2bd) complete. Timing: real 0.187s	user 0.131s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733724,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1183,"lbm_read_time_us":12852,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34447,"lbm_writes_lt_1ms":543,"mutex_wait_us":424,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8448,"update_count":2500}
I20260812 06:19:29.106340 27506 maintenance_manager.cc:419] P 608b5dab79144bc7b88c0ed82eeda305: Scheduling FlushDeltaMemStoresOp(a266596c4fb048edbe25f4c77cb4d2bd): perf score=10.126437
I20260812 06:19:29.157636 27384 maintenance_manager.cc:643] P 608b5dab79144bc7b88c0ed82eeda305: FlushDeltaMemStoresOp(a266596c4fb048edbe25f4c77cb4d2bd) complete. Timing: real 0.051s	user 0.024s	sys 0.024s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":22970,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:29.158243 27506 maintenance_manager.cc:419] P 608b5dab79144bc7b88c0ed82eeda305: Scheduling FlushDeltaMemStoresOp(a266596c4fb048edbe25f4c77cb4d2bd): perf score=2.188937
I20260812 06:19:29.181387 27384 maintenance_manager.cc:643] P 608b5dab79144bc7b88c0ed82eeda305: FlushDeltaMemStoresOp(a266596c4fb048edbe25f4c77cb4d2bd) complete. Timing: real 0.023s	user 0.016s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7224,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:29.181983 27506 maintenance_manager.cc:419] P 608b5dab79144bc7b88c0ed82eeda305: Scheduling MajorDeltaCompactionOp(a266596c4fb048edbe25f4c77cb4d2bd): perf score=1.000000
I20260812 06:19:29.363705 27384 maintenance_manager.cc:643] P 608b5dab79144bc7b88c0ed82eeda305: MajorDeltaCompactionOp(a266596c4fb048edbe25f4c77cb4d2bd) complete. Timing: real 0.181s	user 0.113s	sys 0.059s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631314,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":710,"lbm_read_time_us":10634,"lbm_reads_lt_1ms":464,"lbm_write_time_us":29725,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12544,"update_count":2000}
I20260812 06:19:29.364440 27506 maintenance_manager.cc:419] P 608b5dab79144bc7b88c0ed82eeda305: Scheduling FlushDeltaMemStoresOp(a266596c4fb048edbe25f4c77cb4d2bd): perf score=14.095187
I20260812 06:19:29.420758 27384 maintenance_manager.cc:643] P 608b5dab79144bc7b88c0ed82eeda305: FlushDeltaMemStoresOp(a266596c4fb048edbe25f4c77cb4d2bd) complete. Timing: real 0.056s	user 0.038s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":24662,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:29.421233 27506 maintenance_manager.cc:419] P 608b5dab79144bc7b88c0ed82eeda305: Scheduling FlushDeltaMemStoresOp(a266596c4fb048edbe25f4c77cb4d2bd): perf score=2.188937
I20260812 06:19:29.432844 27384 maintenance_manager.cc:643] P 608b5dab79144bc7b88c0ed82eeda305: FlushDeltaMemStoresOp(a266596c4fb048edbe25f4c77cb4d2bd) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4252,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:29.433440 27506 maintenance_manager.cc:419] P 608b5dab79144bc7b88c0ed82eeda305: Scheduling MajorDeltaCompactionOp(a266596c4fb048edbe25f4c77cb4d2bd): perf score=1.000000
I20260812 06:19:29.595985 27384 maintenance_manager.cc:643] P 608b5dab79144bc7b88c0ed82eeda305: MajorDeltaCompactionOp(a266596c4fb048edbe25f4c77cb4d2bd) complete. Timing: real 0.162s	user 0.126s	sys 0.029s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":274,"lbm_read_time_us":10671,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31466,"lbm_writes_lt_1ms":543,"mutex_wait_us":26,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":105216,"update_count":2500}
I20260812 06:19:29.596696 27506 maintenance_manager.cc:419] P 608b5dab79144bc7b88c0ed82eeda305: Scheduling FlushDeltaMemStoresOp(a266596c4fb048edbe25f4c77cb4d2bd): perf score=14.095187
I20260812 06:19:29.653836 27384 maintenance_manager.cc:643] P 608b5dab79144bc7b88c0ed82eeda305: FlushDeltaMemStoresOp(a266596c4fb048edbe25f4c77cb4d2bd) complete. Timing: real 0.057s	user 0.028s	sys 0.015s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20969,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:29.654373 27506 maintenance_manager.cc:419] P 608b5dab79144bc7b88c0ed82eeda305: Scheduling FlushDeltaMemStoresOp(a266596c4fb048edbe25f4c77cb4d2bd): perf score=2.188937
I20260812 06:19:29.670354 27384 maintenance_manager.cc:643] P 608b5dab79144bc7b88c0ed82eeda305: FlushDeltaMemStoresOp(a266596c4fb048edbe25f4c77cb4d2bd) complete. Timing: real 0.016s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6060,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:29.670987 27506 maintenance_manager.cc:419] P 608b5dab79144bc7b88c0ed82eeda305: Scheduling FlushMRSOp(a266596c4fb048edbe25f4c77cb4d2bd): perf score=1.000000
I20260812 06:19:29.703430 27384 maintenance_manager.cc:643] P 608b5dab79144bc7b88c0ed82eeda305: FlushMRSOp(a266596c4fb048edbe25f4c77cb4d2bd) complete. Timing: real 0.032s	user 0.027s	sys 0.005s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":74,"dirs.run_cpu_time_us":282,"dirs.run_wall_time_us":1308,"drs_written":1,"lbm_read_time_us":43,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1996,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:29.704201 27506 maintenance_manager.cc:419] P 608b5dab79144bc7b88c0ed82eeda305: Scheduling LogGCOp(a266596c4fb048edbe25f4c77cb4d2bd): free 132571256 bytes of WAL
I20260812 06:19:29.704444 27384 log_reader.cc:385] T a266596c4fb048edbe25f4c77cb4d2bd: removed 13 log segments from log reader
I20260812 06:19:29.704496 27384 log.cc:1079] T a266596c4fb048edbe25f4c77cb4d2bd P 608b5dab79144bc7b88c0ed82eeda305: Deleting log segment in path: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566024816-27206-0/minicluster-data/ts-0-root/wals/a266596c4fb048edbe25f4c77cb4d2bd/wal-000000014 (ops 65-69)
I20260812 06:19:29.704556 27384 log.cc:1079] T a266596c4fb048edbe25f4c77cb4d2bd P 608b5dab79144bc7b88c0ed82eeda305: Deleting log segment in path: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566024816-27206-0/minicluster-data/ts-0-root/wals/a266596c4fb048edbe25f4c77cb4d2bd/wal-000000015 (ops 70-74)
I20260812 06:19:29.704610 27384 log.cc:1079] T a266596c4fb048edbe25f4c77cb4d2bd P 608b5dab79144bc7b88c0ed82eeda305: Deleting log segment in path: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566024816-27206-0/minicluster-data/ts-0-root/wals/a266596c4fb048edbe25f4c77cb4d2bd/wal-000000016 (ops 75-79)
I20260812 06:19:29.704654 27384 log.cc:1079] T a266596c4fb048edbe25f4c77cb4d2bd P 608b5dab79144bc7b88c0ed82eeda305: Deleting log segment in path: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566024816-27206-0/minicluster-data/ts-0-root/wals/a266596c4fb048edbe25f4c77cb4d2bd/wal-000000017 (ops 80-84)
I20260812 06:19:29.704701 27384 log.cc:1079] T a266596c4fb048edbe25f4c77cb4d2bd P 608b5dab79144bc7b88c0ed82eeda305: Deleting log segment in path: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566024816-27206-0/minicluster-data/ts-0-root/wals/a266596c4fb048edbe25f4c77cb4d2bd/wal-000000018 (ops 85-89)
I20260812 06:19:29.704768 27384 log.cc:1079] T a266596c4fb048edbe25f4c77cb4d2bd P 608b5dab79144bc7b88c0ed82eeda305: Deleting log segment in path: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566024816-27206-0/minicluster-data/ts-0-root/wals/a266596c4fb048edbe25f4c77cb4d2bd/wal-000000019 (ops 90-94)
I20260812 06:19:29.705240 27384 log.cc:1079] T a266596c4fb048edbe25f4c77cb4d2bd P 608b5dab79144bc7b88c0ed82eeda305: Deleting log segment in path: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566024816-27206-0/minicluster-data/ts-0-root/wals/a266596c4fb048edbe25f4c77cb4d2bd/wal-000000020 (ops 95-98)
I20260812 06:19:29.705365 27384 log.cc:1079] T a266596c4fb048edbe25f4c77cb4d2bd P 608b5dab79144bc7b88c0ed82eeda305: Deleting log segment in path: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566024816-27206-0/minicluster-data/ts-0-root/wals/a266596c4fb048edbe25f4c77cb4d2bd/wal-000000021 (ops 99-103)
I20260812 06:19:29.705451 27384 log.cc:1079] T a266596c4fb048edbe25f4c77cb4d2bd P 608b5dab79144bc7b88c0ed82eeda305: Deleting log segment in path: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566024816-27206-0/minicluster-data/ts-0-root/wals/a266596c4fb048edbe25f4c77cb4d2bd/wal-000000022 (ops 104-108)
I20260812 06:19:29.705484 27384 log.cc:1079] T a266596c4fb048edbe25f4c77cb4d2bd P 608b5dab79144bc7b88c0ed82eeda305: Deleting log segment in path: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566024816-27206-0/minicluster-data/ts-0-root/wals/a266596c4fb048edbe25f4c77cb4d2bd/wal-000000023 (ops 109-112)
I20260812 06:19:29.705528 27384 log.cc:1079] T a266596c4fb048edbe25f4c77cb4d2bd P 608b5dab79144bc7b88c0ed82eeda305: Deleting log segment in path: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566024816-27206-0/minicluster-data/ts-0-root/wals/a266596c4fb048edbe25f4c77cb4d2bd/wal-000000024 (ops 113-117)
I20260812 06:19:29.705571 27384 log.cc:1079] T a266596c4fb048edbe25f4c77cb4d2bd P 608b5dab79144bc7b88c0ed82eeda305: Deleting log segment in path: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566024816-27206-0/minicluster-data/ts-0-root/wals/a266596c4fb048edbe25f4c77cb4d2bd/wal-000000025 (ops 118-122)
I20260812 06:19:29.705651 27384 log.cc:1079] T a266596c4fb048edbe25f4c77cb4d2bd P 608b5dab79144bc7b88c0ed82eeda305: Deleting log segment in path: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566024816-27206-0/minicluster-data/ts-0-root/wals/a266596c4fb048edbe25f4c77cb4d2bd/wal-000000026 (ops 123-127)
I20260812 06:19:29.736697 27384 maintenance_manager.cc:643] P 608b5dab79144bc7b88c0ed82eeda305: LogGCOp(a266596c4fb048edbe25f4c77cb4d2bd) complete. Timing: real 0.032s	user 0.003s	sys 0.027s Metrics: {}
I20260812 06:19:29.737386 27506 maintenance_manager.cc:419] P 608b5dab79144bc7b88c0ed82eeda305: Scheduling UndoDeltaBlockGCOp(a266596c4fb048edbe25f4c77cb4d2bd): 482 bytes on disk
I20260812 06:19:29.737861 27384 maintenance_manager.cc:643] P 608b5dab79144bc7b88c0ed82eeda305: UndoDeltaBlockGCOp(a266596c4fb048edbe25f4c77cb4d2bd) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4}
I20260812 06:19:29.738373 27506 maintenance_manager.cc:419] P 608b5dab79144bc7b88c0ed82eeda305: Scheduling FlushDeltaMemStoresOp(a266596c4fb048edbe25f4c77cb4d2bd): perf score=6.157687
I20260812 06:19:29.774262 27384 maintenance_manager.cc:643] P 608b5dab79144bc7b88c0ed82eeda305: FlushDeltaMemStoresOp(a266596c4fb048edbe25f4c77cb4d2bd) complete. Timing: real 0.036s	user 0.015s	sys 0.014s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":9877,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:19:29.775373 27506 maintenance_manager.cc:419] P 608b5dab79144bc7b88c0ed82eeda305: Scheduling MajorDeltaCompactionOp(a266596c4fb048edbe25f4c77cb4d2bd): perf score=1.000000
I20260812 06:19:30.025938 27384 maintenance_manager.cc:643] P 608b5dab79144bc7b88c0ed82eeda305: MajorDeltaCompactionOp(a266596c4fb048edbe25f4c77cb4d2bd) complete. Timing: real 0.250s	user 0.171s	sys 0.077s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":32938666,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":537,"lbm_read_time_us":18001,"lbm_reads_lt_1ms":765,"lbm_write_time_us":43638,"lbm_writes_lt_1ms":743,"mutex_wait_us":49,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":20736,"thread_start_us":82,"threads_started":1,"update_count":3500}
I20260812 06:19:30.026597 27506 maintenance_manager.cc:419] P 608b5dab79144bc7b88c0ed82eeda305: Scheduling FlushDeltaMemStoresOp(a266596c4fb048edbe25f4c77cb4d2bd): perf score=18.063937
I20260812 06:19:30.092824 27384 maintenance_manager.cc:643] P 608b5dab79144bc7b88c0ed82eeda305: FlushDeltaMemStoresOp(a266596c4fb048edbe25f4c77cb4d2bd) complete. Timing: real 0.066s	user 0.047s	sys 0.016s Metrics: {"bytes_written":20512319,"delete_count":0,"lbm_write_time_us":30370,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:30.094048 27506 maintenance_manager.cc:419] P 608b5dab79144bc7b88c0ed82eeda305: Scheduling FlushDeltaMemStoresOp(a266596c4fb048edbe25f4c77cb4d2bd): perf score=2.188937
I20260812 06:19:30.108204 27384 maintenance_manager.cc:643] P 608b5dab79144bc7b88c0ed82eeda305: FlushDeltaMemStoresOp(a266596c4fb048edbe25f4c77cb4d2bd) complete. Timing: real 0.014s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5807,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:30.108708 27506 maintenance_manager.cc:419] P 608b5dab79144bc7b88c0ed82eeda305: Scheduling MajorDeltaCompactionOp(a266596c4fb048edbe25f4c77cb4d2bd): perf score=1.000000
I20260812 06:19:30.301632 27384 maintenance_manager.cc:643] P 608b5dab79144bc7b88c0ed82eeda305: MajorDeltaCompactionOp(a266596c4fb048edbe25f4c77cb4d2bd) complete. Timing: real 0.193s	user 0.133s	sys 0.060s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28836141,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":226,"lbm_read_time_us":13605,"lbm_reads_lt_1ms":672,"lbm_write_time_us":33619,"lbm_writes_lt_1ms":643,"mutex_wait_us":56,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":12416,"update_count":3000}
I20260812 06:19:30.305905 27506 maintenance_manager.cc:419] P 608b5dab79144bc7b88c0ed82eeda305: Scheduling FlushDeltaMemStoresOp(a266596c4fb048edbe25f4c77cb4d2bd): perf score=14.095187
I20260812 06:19:30.363178 27384 maintenance_manager.cc:643] P 608b5dab79144bc7b88c0ed82eeda305: FlushDeltaMemStoresOp(a266596c4fb048edbe25f4c77cb4d2bd) complete. Timing: real 0.057s	user 0.037s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":25695,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:30.363669 27506 maintenance_manager.cc:419] P 608b5dab79144bc7b88c0ed82eeda305: Scheduling FlushDeltaMemStoresOp(a266596c4fb048edbe25f4c77cb4d2bd): perf score=2.188937
I20260812 06:19:30.375845 27384 maintenance_manager.cc:643] P 608b5dab79144bc7b88c0ed82eeda305: FlushDeltaMemStoresOp(a266596c4fb048edbe25f4c77cb4d2bd) complete. Timing: real 0.012s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4387,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:30.376348 27506 maintenance_manager.cc:419] P 608b5dab79144bc7b88c0ed82eeda305: Scheduling MajorDeltaCompactionOp(a266596c4fb048edbe25f4c77cb4d2bd): perf score=1.000000
I20260812 06:19:30.574240 27384 maintenance_manager.cc:643] P 608b5dab79144bc7b88c0ed82eeda305: MajorDeltaCompactionOp(a266596c4fb048edbe25f4c77cb4d2bd) complete. Timing: real 0.198s	user 0.156s	sys 0.039s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1050,"lbm_read_time_us":14041,"lbm_reads_lt_1ms":572,"lbm_write_time_us":36852,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":542,"mutex_wait_us":384,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":31104,"update_count":2500}
I20260812 06:19:30.574987 27506 maintenance_manager.cc:419] P 608b5dab79144bc7b88c0ed82eeda305: Scheduling FlushDeltaMemStoresOp(a266596c4fb048edbe25f4c77cb4d2bd): perf score=14.095187
I20260812 06:19:30.643483 27384 maintenance_manager.cc:643] P 608b5dab79144bc7b88c0ed82eeda305: FlushDeltaMemStoresOp(a266596c4fb048edbe25f4c77cb4d2bd) complete. Timing: real 0.068s	user 0.024s	sys 0.042s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":29331,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:30.644088 27506 maintenance_manager.cc:419] P 608b5dab79144bc7b88c0ed82eeda305: Scheduling FlushDeltaMemStoresOp(a266596c4fb048edbe25f4c77cb4d2bd): perf score=2.188937
I20260812 06:19:30.655892 27384 maintenance_manager.cc:643] P 608b5dab79144bc7b88c0ed82eeda305: FlushDeltaMemStoresOp(a266596c4fb048edbe25f4c77cb4d2bd) complete. Timing: real 0.012s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4568,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:30.656394 27506 maintenance_manager.cc:419] P 608b5dab79144bc7b88c0ed82eeda305: Scheduling MajorDeltaCompactionOp(a266596c4fb048edbe25f4c77cb4d2bd): perf score=1.000000
I20260812 06:19:30.857767 27384 maintenance_manager.cc:643] P 608b5dab79144bc7b88c0ed82eeda305: MajorDeltaCompactionOp(a266596c4fb048edbe25f4c77cb4d2bd) complete. Timing: real 0.201s	user 0.110s	sys 0.088s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733725,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1130,"lbm_read_time_us":14669,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34979,"lbm_writes_lt_1ms":543,"mutex_wait_us":31,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":16256,"update_count":2500}
I20260812 06:19:30.858659 27506 maintenance_manager.cc:419] P 608b5dab79144bc7b88c0ed82eeda305: Scheduling FlushDeltaMemStoresOp(a266596c4fb048edbe25f4c77cb4d2bd): perf score=10.126437
I20260812 06:19:30.900682 27384 maintenance_manager.cc:643] P 608b5dab79144bc7b88c0ed82eeda305: FlushDeltaMemStoresOp(a266596c4fb048edbe25f4c77cb4d2bd) complete. Timing: real 0.042s	user 0.027s	sys 0.013s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18746,"lbm_writes_lt_1ms":303,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":1500}
I20260812 06:19:30.901460 27506 maintenance_manager.cc:419] P 608b5dab79144bc7b88c0ed82eeda305: Scheduling FlushDeltaMemStoresOp(a266596c4fb048edbe25f4c77cb4d2bd): perf score=2.188937
I20260812 06:19:30.915221 27384 maintenance_manager.cc:643] P 608b5dab79144bc7b88c0ed82eeda305: FlushDeltaMemStoresOp(a266596c4fb048edbe25f4c77cb4d2bd) complete. Timing: real 0.014s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5520,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:30.915851 27506 maintenance_manager.cc:419] P 608b5dab79144bc7b88c0ed82eeda305: Scheduling MajorDeltaCompactionOp(a266596c4fb048edbe25f4c77cb4d2bd): perf score=1.000000
I20260812 06:19:31.088593 27384 maintenance_manager.cc:643] P 608b5dab79144bc7b88c0ed82eeda305: MajorDeltaCompactionOp(a266596c4fb048edbe25f4c77cb4d2bd) complete. Timing: real 0.172s	user 0.116s	sys 0.056s 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":720,"lbm_read_time_us":10123,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27330,"lbm_writes_lt_1ms":443,"mutex_wait_us":65,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12800,"update_count":2000}
I20260812 06:19:31.089567 27506 maintenance_manager.cc:419] P 608b5dab79144bc7b88c0ed82eeda305: Scheduling FlushDeltaMemStoresOp(a266596c4fb048edbe25f4c77cb4d2bd): perf score=10.126437
I20260812 06:19:31.128404 27384 maintenance_manager.cc:643] P 608b5dab79144bc7b88c0ed82eeda305: FlushDeltaMemStoresOp(a266596c4fb048edbe25f4c77cb4d2bd) complete. Timing: real 0.039s	user 0.021s	sys 0.015s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":16715,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:31.129273 27506 maintenance_manager.cc:419] P 608b5dab79144bc7b88c0ed82eeda305: Scheduling FlushDeltaMemStoresOp(a266596c4fb048edbe25f4c77cb4d2bd): perf score=2.188937
I20260812 06:19:31.151086 27384 maintenance_manager.cc:643] P 608b5dab79144bc7b88c0ed82eeda305: FlushDeltaMemStoresOp(a266596c4fb048edbe25f4c77cb4d2bd) complete. Timing: real 0.021s	user 0.018s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7148,"lbm_writes_lt_1ms":103,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":500}
I20260812 06:19:31.151906 27506 maintenance_manager.cc:419] P 608b5dab79144bc7b88c0ed82eeda305: Scheduling MajorDeltaCompactionOp(a266596c4fb048edbe25f4c77cb4d2bd): perf score=1.000000
I20260812 06:19:31.288463 27384 maintenance_manager.cc:643] P 608b5dab79144bc7b88c0ed82eeda305: MajorDeltaCompactionOp(a266596c4fb048edbe25f4c77cb4d2bd) complete. Timing: real 0.136s	user 0.103s	sys 0.031s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631311,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":359,"lbm_read_time_us":10189,"lbm_reads_lt_1ms":464,"lbm_write_time_us":25392,"lbm_writes_lt_1ms":443,"mutex_wait_us":42,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11392,"update_count":2000}
I20260812 06:19:31.289317 27506 maintenance_manager.cc:419] P 608b5dab79144bc7b88c0ed82eeda305: Scheduling FlushDeltaMemStoresOp(a266596c4fb048edbe25f4c77cb4d2bd): perf score=10.126437
I20260812 06:19:31.337240 27384 maintenance_manager.cc:643] P 608b5dab79144bc7b88c0ed82eeda305: FlushDeltaMemStoresOp(a266596c4fb048edbe25f4c77cb4d2bd) complete. Timing: real 0.048s	user 0.020s	sys 0.024s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":23574,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:19:31.337795 27506 maintenance_manager.cc:419] P 608b5dab79144bc7b88c0ed82eeda305: Scheduling FlushDeltaMemStoresOp(a266596c4fb048edbe25f4c77cb4d2bd): perf score=2.188937
I20260812 06:19:31.350136 27384 maintenance_manager.cc:643] P 608b5dab79144bc7b88c0ed82eeda305: FlushDeltaMemStoresOp(a266596c4fb048edbe25f4c77cb4d2bd) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4532,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:31.350716 27506 maintenance_manager.cc:419] P 608b5dab79144bc7b88c0ed82eeda305: Scheduling FlushMRSOp(a266596c4fb048edbe25f4c77cb4d2bd): perf score=1.000000
I20260812 06:19:31.381901 27384 maintenance_manager.cc:643] P 608b5dab79144bc7b88c0ed82eeda305: FlushMRSOp(a266596c4fb048edbe25f4c77cb4d2bd) complete. Timing: real 0.031s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1234475,"cfile_init":1,"dirs.queue_time_us":77,"dirs.run_cpu_time_us":255,"dirs.run_wall_time_us":1691,"drs_written":1,"lbm_read_time_us":44,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1841,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:19:31.382718 27506 maintenance_manager.cc:419] P 608b5dab79144bc7b88c0ed82eeda305: Scheduling LogGCOp(a266596c4fb048edbe25f4c77cb4d2bd): free 120553684 bytes of WAL
I20260812 06:19:31.382968 27384 log_reader.cc:385] T a266596c4fb048edbe25f4c77cb4d2bd: removed 12 log segments from log reader
I20260812 06:19:31.383014 27384 log.cc:1079] T a266596c4fb048edbe25f4c77cb4d2bd P 608b5dab79144bc7b88c0ed82eeda305: Deleting log segment in path: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566024816-27206-0/minicluster-data/ts-0-root/wals/a266596c4fb048edbe25f4c77cb4d2bd/wal-000000027 (ops 128-132)
I20260812 06:19:31.383046 27384 log.cc:1079] T a266596c4fb048edbe25f4c77cb4d2bd P 608b5dab79144bc7b88c0ed82eeda305: Deleting log segment in path: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566024816-27206-0/minicluster-data/ts-0-root/wals/a266596c4fb048edbe25f4c77cb4d2bd/wal-000000028 (ops 133-137)
I20260812 06:19:31.383114 27384 log.cc:1079] T a266596c4fb048edbe25f4c77cb4d2bd P 608b5dab79144bc7b88c0ed82eeda305: Deleting log segment in path: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566024816-27206-0/minicluster-data/ts-0-root/wals/a266596c4fb048edbe25f4c77cb4d2bd/wal-000000029 (ops 138-142)
I20260812 06:19:31.383165 27384 log.cc:1079] T a266596c4fb048edbe25f4c77cb4d2bd P 608b5dab79144bc7b88c0ed82eeda305: Deleting log segment in path: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566024816-27206-0/minicluster-data/ts-0-root/wals/a266596c4fb048edbe25f4c77cb4d2bd/wal-000000030 (ops 143-147)
I20260812 06:19:31.383234 27384 log.cc:1079] T a266596c4fb048edbe25f4c77cb4d2bd P 608b5dab79144bc7b88c0ed82eeda305: Deleting log segment in path: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566024816-27206-0/minicluster-data/ts-0-root/wals/a266596c4fb048edbe25f4c77cb4d2bd/wal-000000031 (ops 148-152)
I20260812 06:19:31.383279 27384 log.cc:1079] T a266596c4fb048edbe25f4c77cb4d2bd P 608b5dab79144bc7b88c0ed82eeda305: Deleting log segment in path: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566024816-27206-0/minicluster-data/ts-0-root/wals/a266596c4fb048edbe25f4c77cb4d2bd/wal-000000032 (ops 153-156)
I20260812 06:19:31.383329 27384 log.cc:1079] T a266596c4fb048edbe25f4c77cb4d2bd P 608b5dab79144bc7b88c0ed82eeda305: Deleting log segment in path: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566024816-27206-0/minicluster-data/ts-0-root/wals/a266596c4fb048edbe25f4c77cb4d2bd/wal-000000033 (ops 157-161)
I20260812 06:19:31.383376 27384 log.cc:1079] T a266596c4fb048edbe25f4c77cb4d2bd P 608b5dab79144bc7b88c0ed82eeda305: Deleting log segment in path: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566024816-27206-0/minicluster-data/ts-0-root/wals/a266596c4fb048edbe25f4c77cb4d2bd/wal-000000034 (ops 162-166)
I20260812 06:19:31.383419 27384 log.cc:1079] T a266596c4fb048edbe25f4c77cb4d2bd P 608b5dab79144bc7b88c0ed82eeda305: Deleting log segment in path: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566024816-27206-0/minicluster-data/ts-0-root/wals/a266596c4fb048edbe25f4c77cb4d2bd/wal-000000035 (ops 167-170)
I20260812 06:19:31.383463 27384 log.cc:1079] T a266596c4fb048edbe25f4c77cb4d2bd P 608b5dab79144bc7b88c0ed82eeda305: Deleting log segment in path: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566024816-27206-0/minicluster-data/ts-0-root/wals/a266596c4fb048edbe25f4c77cb4d2bd/wal-000000036 (ops 171-175)
I20260812 06:19:31.383507 27384 log.cc:1079] T a266596c4fb048edbe25f4c77cb4d2bd P 608b5dab79144bc7b88c0ed82eeda305: Deleting log segment in path: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566024816-27206-0/minicluster-data/ts-0-root/wals/a266596c4fb048edbe25f4c77cb4d2bd/wal-000000037 (ops 176-180)
I20260812 06:19:31.383555 27384 log.cc:1079] T a266596c4fb048edbe25f4c77cb4d2bd P 608b5dab79144bc7b88c0ed82eeda305: Deleting log segment in path: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566024816-27206-0/minicluster-data/ts-0-root/wals/a266596c4fb048edbe25f4c77cb4d2bd/wal-000000038 (ops 181-185)
I20260812 06:19:31.414000 27384 maintenance_manager.cc:643] P 608b5dab79144bc7b88c0ed82eeda305: LogGCOp(a266596c4fb048edbe25f4c77cb4d2bd) complete. Timing: real 0.031s	user 0.000s	sys 0.028s Metrics: {}
I20260812 06:19:31.414470 27506 maintenance_manager.cc:419] P 608b5dab79144bc7b88c0ed82eeda305: Scheduling UndoDeltaBlockGCOp(a266596c4fb048edbe25f4c77cb4d2bd): 473 bytes on disk
I20260812 06:19:31.414973 27384 maintenance_manager.cc:643] P 608b5dab79144bc7b88c0ed82eeda305: UndoDeltaBlockGCOp(a266596c4fb048edbe25f4c77cb4d2bd) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":71,"lbm_reads_lt_1ms":4}
I20260812 06:19:31.415674 27506 maintenance_manager.cc:419] P 608b5dab79144bc7b88c0ed82eeda305: Scheduling FlushDeltaMemStoresOp(a266596c4fb048edbe25f4c77cb4d2bd): perf score=3.181125
I20260812 06:19:31.430327 27384 maintenance_manager.cc:643] P 608b5dab79144bc7b88c0ed82eeda305: FlushDeltaMemStoresOp(a266596c4fb048edbe25f4c77cb4d2bd) complete. Timing: real 0.014s	user 0.012s	sys 0.000s Metrics: {"bytes_written":5005191,"delete_count":0,"lbm_write_time_us":5870,"lbm_writes_lt_1ms":125,"reinsert_count":0,"update_count":610}
I20260812 06:19:31.430830 27506 maintenance_manager.cc:419] P 608b5dab79144bc7b88c0ed82eeda305: Scheduling FlushDeltaMemStoresOp(a266596c4fb048edbe25f4c77cb4d2bd): perf score=2.188937
I20260812 06:19:31.443357 27384 maintenance_manager.cc:643] P 608b5dab79144bc7b88c0ed82eeda305: FlushDeltaMemStoresOp(a266596c4fb048edbe25f4c77cb4d2bd) complete. Timing: real 0.012s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3200105,"delete_count":0,"lbm_write_time_us":4664,"lbm_writes_lt_1ms":81,"reinsert_count":0,"update_count":390}
I20260812 06:19:31.443993 27506 maintenance_manager.cc:419] P 608b5dab79144bc7b88c0ed82eeda305: Scheduling MajorDeltaCompactionOp(a266596c4fb048edbe25f4c77cb4d2bd): perf score=1.000000
I20260812 06:19:31.636121 27384 maintenance_manager.cc:643] P 608b5dab79144bc7b88c0ed82eeda305: MajorDeltaCompactionOp(a266596c4fb048edbe25f4c77cb4d2bd) complete. Timing: real 0.192s	user 0.140s	sys 0.044s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836353,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":407,"lbm_read_time_us":12498,"lbm_reads_lt_1ms":674,"lbm_write_time_us":38134,"lbm_writes_lt_1ms":643,"mutex_wait_us":20,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3456,"thread_start_us":83,"threads_started":1,"update_count":3000}
I20260812 06:19:31.636852 27506 maintenance_manager.cc:419] P 608b5dab79144bc7b88c0ed82eeda305: Scheduling FlushDeltaMemStoresOp(a266596c4fb048edbe25f4c77cb4d2bd): perf score=14.095187
I20260812 06:19:31.696596 27384 maintenance_manager.cc:643] P 608b5dab79144bc7b88c0ed82eeda305: FlushDeltaMemStoresOp(a266596c4fb048edbe25f4c77cb4d2bd) complete. Timing: real 0.060s	user 0.033s	sys 0.017s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23476,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:31.697080 27506 maintenance_manager.cc:419] P 608b5dab79144bc7b88c0ed82eeda305: Scheduling FlushDeltaMemStoresOp(a266596c4fb048edbe25f4c77cb4d2bd): perf score=2.188937
I20260812 06:19:31.708094 27384 maintenance_manager.cc:643] P 608b5dab79144bc7b88c0ed82eeda305: FlushDeltaMemStoresOp(a266596c4fb048edbe25f4c77cb4d2bd) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4087,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:31.708580 27506 maintenance_manager.cc:419] P 608b5dab79144bc7b88c0ed82eeda305: Scheduling MajorDeltaCompactionOp(a266596c4fb048edbe25f4c77cb4d2bd): perf score=1.000000
I20260812 06:19:31.744496 27206 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.372s	user 1.986s	sys 0.200s
I20260812 06:19:31.814344 27206 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.069s	user 0.002s	sys 0.000s
I20260812 06:19:31.815061 27206 tablet_server.cc:179] TabletServer@127.26.145.129:0 shutting down...
I20260812 06:19:31.859035 27384 maintenance_manager.cc:643] P 608b5dab79144bc7b88c0ed82eeda305: MajorDeltaCompactionOp(a266596c4fb048edbe25f4c77cb4d2bd) complete. Timing: real 0.150s	user 0.119s	sys 0.031s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":868,"lbm_read_time_us":11680,"lbm_reads_lt_1ms":568,"lbm_write_time_us":29355,"lbm_writes_lt_1ms":543,"mutex_wait_us":294,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":267648,"update_count":2500}
I20260812 06:19:31.859958 27206 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:31.860512 27206 tablet_replica.cc:333] T a266596c4fb048edbe25f4c77cb4d2bd P 608b5dab79144bc7b88c0ed82eeda305: stopping tablet replica
I20260812 06:19:31.860754 27206 raft_consensus.cc:2243] T a266596c4fb048edbe25f4c77cb4d2bd P 608b5dab79144bc7b88c0ed82eeda305 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:31.860991 27206 raft_consensus.cc:2272] T a266596c4fb048edbe25f4c77cb4d2bd P 608b5dab79144bc7b88c0ed82eeda305 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:31.868898 27206 tablet_server.cc:196] TabletServer@127.26.145.129:0 shutdown complete.
I20260812 06:19:31.906767 27206 master.cc:562] Master@127.26.145.190:36043 shutting down...
I20260812 06:19:31.912231 27206 raft_consensus.cc:2243] T 00000000000000000000000000000000 P d0371c7e27a34c5087517274770817cc [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:31.912510 27206 raft_consensus.cc:2272] T 00000000000000000000000000000000 P d0371c7e27a34c5087517274770817cc [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:31.912572 27206 tablet_replica.cc:333] T 00000000000000000000000000000000 P d0371c7e27a34c5087517274770817cc: stopping tablet replica
I20260812 06:19:31.926077 27206 master.cc:584] Master@127.26.145.190:36043 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5986 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:19:32.023058 27206 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.26.145.190:42267
I20260812 06:19:32.023581 27206 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:32.026275 27561 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:19:32.026288 27567 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:19:32.026345 27563 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:19:32.026379 27206 server_base.cc:1061] running on GCE node
I20260812 06:19:32.027063 27206 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:32.027129 27206 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:19:32.027158 27206 hybrid_clock.cc:648] HybridClock initialized: now 1786515572027156 us; error 0 us; skew 500 ppm
I20260812 06:19:32.028115 27206 webserver.cc:533] Webserver started at http://127.26.145.190:35017/ using document root <none> and password file <none>
I20260812 06:19:32.028424 27206 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:32.028625 27206 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:32.028774 27206 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:32.029320 27206 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566024816-27206-0/minicluster-data/master-0-root/instance:
uuid: "24a40cbfaf9f408f87f4d1c4400a5738"
format_stamp: "Formatted at 2026-08-12 06:19:32 on dist-test-slave-h6n0"
I20260812 06:19:32.031351 27206 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:19:32.032788 27575 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:19:32.033188 27206 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:32.033335 27206 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566024816-27206-0/minicluster-data/master-0-root
uuid: "24a40cbfaf9f408f87f4d1c4400a5738"
format_stamp: "Formatted at 2026-08-12 06:19:32 on dist-test-slave-h6n0"
I20260812 06:19:32.033448 27206 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566024816-27206-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566024816-27206-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566024816-27206-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:19:32.049561 27206 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:32.050140 27206 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:32.055955 27206 rpc_server.cc:307] RPC server started. Bound to: 127.26.145.190:42267
I20260812 06:19:32.062806 27674 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.26.145.190:42267 every 8 connection(s)
I20260812 06:19:32.066601 27675 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:19:32.068872 27675 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 24a40cbfaf9f408f87f4d1c4400a5738: Bootstrap starting.
I20260812 06:19:32.069702 27675 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 24a40cbfaf9f408f87f4d1c4400a5738: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:32.070876 27675 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 24a40cbfaf9f408f87f4d1c4400a5738: No bootstrap required, opened a new log
I20260812 06:19:32.071463 27675 raft_consensus.cc:359] T 00000000000000000000000000000000 P 24a40cbfaf9f408f87f4d1c4400a5738 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "24a40cbfaf9f408f87f4d1c4400a5738" member_type: VOTER }
I20260812 06:19:32.071719 27675 raft_consensus.cc:385] T 00000000000000000000000000000000 P 24a40cbfaf9f408f87f4d1c4400a5738 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:32.071769 27675 raft_consensus.cc:740] T 00000000000000000000000000000000 P 24a40cbfaf9f408f87f4d1c4400a5738 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 24a40cbfaf9f408f87f4d1c4400a5738, State: Initialized, Role: FOLLOWER
I20260812 06:19:32.072016 27675 consensus_queue.cc:260] T 00000000000000000000000000000000 P 24a40cbfaf9f408f87f4d1c4400a5738 [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: "24a40cbfaf9f408f87f4d1c4400a5738" member_type: VOTER }
I20260812 06:19:32.072135 27675 raft_consensus.cc:399] T 00000000000000000000000000000000 P 24a40cbfaf9f408f87f4d1c4400a5738 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:32.072247 27675 raft_consensus.cc:493] T 00000000000000000000000000000000 P 24a40cbfaf9f408f87f4d1c4400a5738 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:32.072345 27675 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 24a40cbfaf9f408f87f4d1c4400a5738 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:32.073391 27675 raft_consensus.cc:515] T 00000000000000000000000000000000 P 24a40cbfaf9f408f87f4d1c4400a5738 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "24a40cbfaf9f408f87f4d1c4400a5738" member_type: VOTER }
I20260812 06:19:32.073589 27675 leader_election.cc:304] T 00000000000000000000000000000000 P 24a40cbfaf9f408f87f4d1c4400a5738 [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: 24a40cbfaf9f408f87f4d1c4400a5738; no voters: 
I20260812 06:19:32.073865 27675 leader_election.cc:290] T 00000000000000000000000000000000 P 24a40cbfaf9f408f87f4d1c4400a5738 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:32.074131 27683 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 24a40cbfaf9f408f87f4d1c4400a5738 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:32.074400 27683 raft_consensus.cc:697] T 00000000000000000000000000000000 P 24a40cbfaf9f408f87f4d1c4400a5738 [term 1 LEADER]: Becoming Leader. State: Replica: 24a40cbfaf9f408f87f4d1c4400a5738, State: Running, Role: LEADER
I20260812 06:19:32.074599 27675 sys_catalog.cc:565] T 00000000000000000000000000000000 P 24a40cbfaf9f408f87f4d1c4400a5738 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:32.074661 27683 consensus_queue.cc:237] T 00000000000000000000000000000000 P 24a40cbfaf9f408f87f4d1c4400a5738 [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: "24a40cbfaf9f408f87f4d1c4400a5738" member_type: VOTER }
I20260812 06:19:32.075229 27685 sys_catalog.cc:455] T 00000000000000000000000000000000 P 24a40cbfaf9f408f87f4d1c4400a5738 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 24a40cbfaf9f408f87f4d1c4400a5738. Latest consensus state: current_term: 1 leader_uuid: "24a40cbfaf9f408f87f4d1c4400a5738" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "24a40cbfaf9f408f87f4d1c4400a5738" member_type: VOTER } }
I20260812 06:19:32.075344 27685 sys_catalog.cc:458] T 00000000000000000000000000000000 P 24a40cbfaf9f408f87f4d1c4400a5738 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:32.075481 27684 sys_catalog.cc:455] T 00000000000000000000000000000000 P 24a40cbfaf9f408f87f4d1c4400a5738 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "24a40cbfaf9f408f87f4d1c4400a5738" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "24a40cbfaf9f408f87f4d1c4400a5738" member_type: VOTER } }
I20260812 06:19:32.075559 27684 sys_catalog.cc:458] T 00000000000000000000000000000000 P 24a40cbfaf9f408f87f4d1c4400a5738 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:32.075791 27692 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:32.076632 27692 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:32.077036 27206 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:32.078462 27692 catalog_manager.cc:1383] Generated new cluster ID: 26ccdf7db5794cd0935730a0c46331d8
I20260812 06:19:32.078557 27692 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:32.097054 27692 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:32.097638 27692 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:32.107492 27692 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 24a40cbfaf9f408f87f4d1c4400a5738: Generated new TSK 0
I20260812 06:19:32.107671 27692 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:32.109719 27206 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:32.112291 27718 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:19:32.112317 27716 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:19:32.112334 27721 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:19:32.112695 27206 server_base.cc:1061] running on GCE node
I20260812 06:19:32.113090 27206 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:32.113160 27206 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:19:32.113186 27206 hybrid_clock.cc:648] HybridClock initialized: now 1786515572113185 us; error 0 us; skew 500 ppm
I20260812 06:19:32.114494 27206 webserver.cc:533] Webserver started at http://127.26.145.129:41521/ using document root <none> and password file <none>
I20260812 06:19:32.114811 27206 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:32.114890 27206 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:32.114970 27206 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:32.115388 27206 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566024816-27206-0/minicluster-data/ts-0-root/instance:
uuid: "a0e34134d1f747f4857d47e9197d4871"
format_stamp: "Formatted at 2026-08-12 06:19:32 on dist-test-slave-h6n0"
I20260812 06:19:32.117172 27206 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:32.118916 27730 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:19:32.119308 27206 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.001s
I20260812 06:19:32.119410 27206 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566024816-27206-0/minicluster-data/ts-0-root
uuid: "a0e34134d1f747f4857d47e9197d4871"
format_stamp: "Formatted at 2026-08-12 06:19:32 on dist-test-slave-h6n0"
I20260812 06:19:32.119513 27206 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566024816-27206-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566024816-27206-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566024816-27206-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:19:32.126251 27206 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:32.126936 27206 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:32.127447 27206 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:32.128010 27206 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:32.128106 27206 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:32.128163 27206 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:32.128214 27206 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:32.133005 27206 rpc_server.cc:307] RPC server started. Bound to: 127.26.145.129:35609
I20260812 06:19:32.133026 27844 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.26.145.129:35609 every 8 connection(s)
I20260812 06:19:32.142419 27846 heartbeater.cc:344] Connected to a master server at 127.26.145.190:42267
I20260812 06:19:32.142657 27846 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:32.142944 27846 heartbeater.cc:507] Master 127.26.145.190:42267 requested a full tablet report, sending...
I20260812 06:19:32.143987 27605 ts_manager.cc:194] Registered new tserver with Master: a0e34134d1f747f4857d47e9197d4871 (127.26.145.129:35609)
I20260812 06:19:32.144755 27206 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.011307554s
I20260812 06:19:32.144912 27605 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:56400
I20260812 06:19:32.153389 27605 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:56412:
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:19:32.163348 27777 tablet_service.cc:1511] Processing CreateTablet for tablet 500941768b6f491d9d3b82001870c17f (DEFAULT_TABLE table=heavy-update-compaction-test [id=4fbc1f71e03041c9ba2e870e50dbc581]), partition=
I20260812 06:19:32.163641 27777 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 500941768b6f491d9d3b82001870c17f. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:32.166042 27865 tablet_bootstrap.cc:492] T 500941768b6f491d9d3b82001870c17f P a0e34134d1f747f4857d47e9197d4871: Bootstrap starting.
I20260812 06:19:32.167424 27865 tablet_bootstrap.cc:654] T 500941768b6f491d9d3b82001870c17f P a0e34134d1f747f4857d47e9197d4871: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:32.168779 27865 tablet_bootstrap.cc:492] T 500941768b6f491d9d3b82001870c17f P a0e34134d1f747f4857d47e9197d4871: No bootstrap required, opened a new log
I20260812 06:19:32.168920 27865 ts_tablet_manager.cc:1403] T 500941768b6f491d9d3b82001870c17f P a0e34134d1f747f4857d47e9197d4871: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:19:32.169554 27865 raft_consensus.cc:359] T 500941768b6f491d9d3b82001870c17f P a0e34134d1f747f4857d47e9197d4871 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a0e34134d1f747f4857d47e9197d4871" member_type: VOTER last_known_addr { host: "127.26.145.129" port: 35609 } }
I20260812 06:19:32.169670 27865 raft_consensus.cc:385] T 500941768b6f491d9d3b82001870c17f P a0e34134d1f747f4857d47e9197d4871 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:32.169720 27865 raft_consensus.cc:740] T 500941768b6f491d9d3b82001870c17f P a0e34134d1f747f4857d47e9197d4871 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: a0e34134d1f747f4857d47e9197d4871, State: Initialized, Role: FOLLOWER
I20260812 06:19:32.169869 27865 consensus_queue.cc:260] T 500941768b6f491d9d3b82001870c17f P a0e34134d1f747f4857d47e9197d4871 [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: "a0e34134d1f747f4857d47e9197d4871" member_type: VOTER last_known_addr { host: "127.26.145.129" port: 35609 } }
I20260812 06:19:32.169970 27865 raft_consensus.cc:399] T 500941768b6f491d9d3b82001870c17f P a0e34134d1f747f4857d47e9197d4871 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:32.170020 27865 raft_consensus.cc:493] T 500941768b6f491d9d3b82001870c17f P a0e34134d1f747f4857d47e9197d4871 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:32.170076 27865 raft_consensus.cc:3060] T 500941768b6f491d9d3b82001870c17f P a0e34134d1f747f4857d47e9197d4871 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:32.170972 27865 raft_consensus.cc:515] T 500941768b6f491d9d3b82001870c17f P a0e34134d1f747f4857d47e9197d4871 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a0e34134d1f747f4857d47e9197d4871" member_type: VOTER last_known_addr { host: "127.26.145.129" port: 35609 } }
I20260812 06:19:32.171147 27865 leader_election.cc:304] T 500941768b6f491d9d3b82001870c17f P a0e34134d1f747f4857d47e9197d4871 [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: a0e34134d1f747f4857d47e9197d4871; no voters: 
I20260812 06:19:32.171386 27865 leader_election.cc:290] T 500941768b6f491d9d3b82001870c17f P a0e34134d1f747f4857d47e9197d4871 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:32.171703 27868 raft_consensus.cc:2804] T 500941768b6f491d9d3b82001870c17f P a0e34134d1f747f4857d47e9197d4871 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:32.171784 27865 ts_tablet_manager.cc:1434] T 500941768b6f491d9d3b82001870c17f P a0e34134d1f747f4857d47e9197d4871: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:19:32.171869 27846 heartbeater.cc:499] Master 127.26.145.190:42267 was elected leader, sending a full tablet report...
I20260812 06:19:32.171931 27868 raft_consensus.cc:697] T 500941768b6f491d9d3b82001870c17f P a0e34134d1f747f4857d47e9197d4871 [term 1 LEADER]: Becoming Leader. State: Replica: a0e34134d1f747f4857d47e9197d4871, State: Running, Role: LEADER
I20260812 06:19:32.172087 27868 consensus_queue.cc:237] T 500941768b6f491d9d3b82001870c17f P a0e34134d1f747f4857d47e9197d4871 [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: "a0e34134d1f747f4857d47e9197d4871" member_type: VOTER last_known_addr { host: "127.26.145.129" port: 35609 } }
I20260812 06:19:32.173987 27604 catalog_manager.cc:5719] T 500941768b6f491d9d3b82001870c17f P a0e34134d1f747f4857d47e9197d4871 reported cstate change: term changed from 0 to 1, leader changed from <none> to a0e34134d1f747f4857d47e9197d4871 (127.26.145.129). New cstate: current_term: 1 leader_uuid: "a0e34134d1f747f4857d47e9197d4871" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a0e34134d1f747f4857d47e9197d4871" member_type: VOTER last_known_addr { host: "127.26.145.129" port: 35609 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:32.237911 27206 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.058s	user 0.020s	sys 0.004s
I20260812 06:19:32.383919 27847 maintenance_manager.cc:419] P a0e34134d1f747f4857d47e9197d4871: Scheduling FlushMRSOp(500941768b6f491d9d3b82001870c17f): perf score=19.054940
I20260812 06:19:32.541577 27736 maintenance_manager.cc:643] P a0e34134d1f747f4857d47e9197d4871: FlushMRSOp(500941768b6f491d9d3b82001870c17f) complete. Timing: real 0.157s	user 0.109s	sys 0.041s Metrics: {"bytes_written":12307490,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":71,"dirs.run_cpu_time_us":242,"dirs.run_wall_time_us":849,"drs_written":1,"lbm_read_time_us":44,"lbm_reads_lt_1ms":4,"lbm_write_time_us":40282,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1500}
I20260812 06:19:32.542152 27847 maintenance_manager.cc:419] P a0e34134d1f747f4857d47e9197d4871: Scheduling LogGCOp(500941768b6f491d9d3b82001870c17f): free 20743880 bytes of WAL
I20260812 06:19:32.542377 27736 log_reader.cc:385] T 500941768b6f491d9d3b82001870c17f: removed 2 log segments from log reader
I20260812 06:19:32.542419 27736 log.cc:1079] T 500941768b6f491d9d3b82001870c17f P a0e34134d1f747f4857d47e9197d4871: Deleting log segment in path: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566024816-27206-0/minicluster-data/ts-0-root/wals/500941768b6f491d9d3b82001870c17f/wal-000000001 (ops 1-6)
I20260812 06:19:32.542449 27736 log.cc:1079] T 500941768b6f491d9d3b82001870c17f P a0e34134d1f747f4857d47e9197d4871: Deleting log segment in path: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566024816-27206-0/minicluster-data/ts-0-root/wals/500941768b6f491d9d3b82001870c17f/wal-000000002 (ops 7-11)
I20260812 06:19:32.547529 27736 maintenance_manager.cc:643] P a0e34134d1f747f4857d47e9197d4871: LogGCOp(500941768b6f491d9d3b82001870c17f) complete. Timing: real 0.005s	user 0.001s	sys 0.003s Metrics: {}
I20260812 06:19:32.548082 27847 maintenance_manager.cc:419] P a0e34134d1f747f4857d47e9197d4871: Scheduling UndoDeltaBlockGCOp(500941768b6f491d9d3b82001870c17f): 16411396 bytes on disk
I20260812 06:19:32.548640 27736 maintenance_manager.cc:643] P a0e34134d1f747f4857d47e9197d4871: UndoDeltaBlockGCOp(500941768b6f491d9d3b82001870c17f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":76,"lbm_reads_lt_1ms":4}
I20260812 06:19:32.549289 27847 maintenance_manager.cc:419] P a0e34134d1f747f4857d47e9197d4871: Scheduling FlushDeltaMemStoresOp(500941768b6f491d9d3b82001870c17f): perf score=2.188937
I20260812 06:19:32.572081 27736 maintenance_manager.cc:643] P a0e34134d1f747f4857d47e9197d4871: FlushDeltaMemStoresOp(500941768b6f491d9d3b82001870c17f) complete. Timing: real 0.023s	user 0.012s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":7140,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:32.572860 27847 maintenance_manager.cc:419] P a0e34134d1f747f4857d47e9197d4871: Scheduling MajorDeltaCompactionOp(500941768b6f491d9d3b82001870c17f): perf score=1.000000
I20260812 06:19:32.745894 27736 maintenance_manager.cc:643] P a0e34134d1f747f4857d47e9197d4871: MajorDeltaCompactionOp(500941768b6f491d9d3b82001870c17f) complete. Timing: real 0.173s	user 0.105s	sys 0.056s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":994,"lbm_read_time_us":12161,"lbm_reads_lt_1ms":460,"lbm_write_time_us":25820,"lbm_writes_lt_1ms":443,"mutex_wait_us":26,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11520,"thread_start_us":322,"threads_started":5,"update_count":2000}
I20260812 06:19:32.746691 27847 maintenance_manager.cc:419] P a0e34134d1f747f4857d47e9197d4871: Scheduling FlushDeltaMemStoresOp(500941768b6f491d9d3b82001870c17f): perf score=14.095187
I20260812 06:19:32.804941 27736 maintenance_manager.cc:643] P a0e34134d1f747f4857d47e9197d4871: FlushDeltaMemStoresOp(500941768b6f491d9d3b82001870c17f) complete. Timing: real 0.058s	user 0.041s	sys 0.009s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23566,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:32.805462 27847 maintenance_manager.cc:419] P a0e34134d1f747f4857d47e9197d4871: Scheduling MajorDeltaCompactionOp(500941768b6f491d9d3b82001870c17f): perf score=1.000000
I20260812 06:19:32.969455 27736 maintenance_manager.cc:643] P a0e34134d1f747f4857d47e9197d4871: MajorDeltaCompactionOp(500941768b6f491d9d3b82001870c17f) complete. Timing: real 0.164s	user 0.111s	sys 0.052s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672157,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":760,"lbm_read_time_us":11575,"lbm_reads_lt_1ms":463,"lbm_write_time_us":26658,"lbm_writes_lt_1ms":443,"mutex_wait_us":117,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":19456,"update_count":2000}
I20260812 06:19:32.970294 27847 maintenance_manager.cc:419] P a0e34134d1f747f4857d47e9197d4871: Scheduling FlushDeltaMemStoresOp(500941768b6f491d9d3b82001870c17f): perf score=14.095187
I20260812 06:19:33.025547 27736 maintenance_manager.cc:643] P a0e34134d1f747f4857d47e9197d4871: FlushDeltaMemStoresOp(500941768b6f491d9d3b82001870c17f) complete. Timing: real 0.055s	user 0.028s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24944,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:33.026077 27847 maintenance_manager.cc:419] P a0e34134d1f747f4857d47e9197d4871: Scheduling FlushDeltaMemStoresOp(500941768b6f491d9d3b82001870c17f): perf score=2.188937
I20260812 06:19:33.037782 27736 maintenance_manager.cc:643] P a0e34134d1f747f4857d47e9197d4871: FlushDeltaMemStoresOp(500941768b6f491d9d3b82001870c17f) complete. Timing: real 0.012s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4192,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:33.038321 27847 maintenance_manager.cc:419] P a0e34134d1f747f4857d47e9197d4871: Scheduling MajorDeltaCompactionOp(500941768b6f491d9d3b82001870c17f): perf score=1.000000
I20260812 06:19:33.249853 27736 maintenance_manager.cc:643] P a0e34134d1f747f4857d47e9197d4871: MajorDeltaCompactionOp(500941768b6f491d9d3b82001870c17f) complete. Timing: real 0.211s	user 0.156s	sys 0.048s 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":676,"lbm_read_time_us":13017,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32988,"lbm_writes_lt_1ms":543,"mutex_wait_us":311,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4608,"update_count":2500}
I20260812 06:19:33.250701 27847 maintenance_manager.cc:419] P a0e34134d1f747f4857d47e9197d4871: Scheduling FlushDeltaMemStoresOp(500941768b6f491d9d3b82001870c17f): perf score=14.095187
I20260812 06:19:33.304239 27736 maintenance_manager.cc:643] P a0e34134d1f747f4857d47e9197d4871: FlushDeltaMemStoresOp(500941768b6f491d9d3b82001870c17f) complete. Timing: real 0.053s	user 0.023s	sys 0.028s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":23953,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:33.304703 27847 maintenance_manager.cc:419] P a0e34134d1f747f4857d47e9197d4871: Scheduling FlushDeltaMemStoresOp(500941768b6f491d9d3b82001870c17f): perf score=2.188937
I20260812 06:19:33.324136 27736 maintenance_manager.cc:643] P a0e34134d1f747f4857d47e9197d4871: FlushDeltaMemStoresOp(500941768b6f491d9d3b82001870c17f) complete. Timing: real 0.019s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6352,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:33.324847 27847 maintenance_manager.cc:419] P a0e34134d1f747f4857d47e9197d4871: Scheduling MajorDeltaCompactionOp(500941768b6f491d9d3b82001870c17f): perf score=1.000000
I20260812 06:19:33.499423 27736 maintenance_manager.cc:643] P a0e34134d1f747f4857d47e9197d4871: MajorDeltaCompactionOp(500941768b6f491d9d3b82001870c17f) complete. Timing: real 0.174s	user 0.126s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":966,"lbm_read_time_us":11133,"lbm_reads_lt_1ms":564,"lbm_write_time_us":33403,"lbm_writes_lt_1ms":543,"mutex_wait_us":262,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9344,"update_count":2500}
I20260812 06:19:33.500173 27847 maintenance_manager.cc:419] P a0e34134d1f747f4857d47e9197d4871: Scheduling FlushDeltaMemStoresOp(500941768b6f491d9d3b82001870c17f): perf score=14.095187
I20260812 06:19:33.554795 27736 maintenance_manager.cc:643] P a0e34134d1f747f4857d47e9197d4871: FlushDeltaMemStoresOp(500941768b6f491d9d3b82001870c17f) complete. Timing: real 0.054s	user 0.047s	sys 0.007s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24869,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:33.555239 27847 maintenance_manager.cc:419] P a0e34134d1f747f4857d47e9197d4871: Scheduling FlushDeltaMemStoresOp(500941768b6f491d9d3b82001870c17f): perf score=2.188937
I20260812 06:19:33.567924 27736 maintenance_manager.cc:643] P a0e34134d1f747f4857d47e9197d4871: FlushDeltaMemStoresOp(500941768b6f491d9d3b82001870c17f) complete. Timing: real 0.012s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4680,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:33.569110 27847 maintenance_manager.cc:419] P a0e34134d1f747f4857d47e9197d4871: Scheduling MajorDeltaCompactionOp(500941768b6f491d9d3b82001870c17f): perf score=1.000000
I20260812 06:19:33.728241 27736 maintenance_manager.cc:643] P a0e34134d1f747f4857d47e9197d4871: MajorDeltaCompactionOp(500941768b6f491d9d3b82001870c17f) complete. Timing: real 0.159s	user 0.117s	sys 0.041s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":847,"lbm_read_time_us":11550,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32963,"lbm_writes_lt_1ms":543,"mutex_wait_us":84,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":30848,"update_count":2500}
I20260812 06:19:33.728965 27847 maintenance_manager.cc:419] P a0e34134d1f747f4857d47e9197d4871: Scheduling FlushDeltaMemStoresOp(500941768b6f491d9d3b82001870c17f): perf score=10.126437
I20260812 06:19:33.770290 27736 maintenance_manager.cc:643] P a0e34134d1f747f4857d47e9197d4871: FlushDeltaMemStoresOp(500941768b6f491d9d3b82001870c17f) complete. Timing: real 0.041s	user 0.027s	sys 0.011s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":18393,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:33.770807 27847 maintenance_manager.cc:419] P a0e34134d1f747f4857d47e9197d4871: Scheduling FlushDeltaMemStoresOp(500941768b6f491d9d3b82001870c17f): perf score=2.188937
I20260812 06:19:33.783215 27736 maintenance_manager.cc:643] P a0e34134d1f747f4857d47e9197d4871: FlushDeltaMemStoresOp(500941768b6f491d9d3b82001870c17f) complete. Timing: real 0.012s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4861,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:33.783741 27847 maintenance_manager.cc:419] P a0e34134d1f747f4857d47e9197d4871: Scheduling MajorDeltaCompactionOp(500941768b6f491d9d3b82001870c17f): perf score=1.000000
I20260812 06:19:33.920792 27736 maintenance_manager.cc:643] P a0e34134d1f747f4857d47e9197d4871: MajorDeltaCompactionOp(500941768b6f491d9d3b82001870c17f) complete. Timing: real 0.137s	user 0.105s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672275,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":255,"lbm_read_time_us":11104,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25383,"lbm_writes_lt_1ms":443,"mutex_wait_us":40,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3200,"update_count":2000}
I20260812 06:19:33.921337 27847 maintenance_manager.cc:419] P a0e34134d1f747f4857d47e9197d4871: Scheduling FlushDeltaMemStoresOp(500941768b6f491d9d3b82001870c17f): perf score=10.126437
I20260812 06:19:33.966289 27736 maintenance_manager.cc:643] P a0e34134d1f747f4857d47e9197d4871: FlushDeltaMemStoresOp(500941768b6f491d9d3b82001870c17f) complete. Timing: real 0.045s	user 0.016s	sys 0.023s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18920,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:33.966794 27847 maintenance_manager.cc:419] P a0e34134d1f747f4857d47e9197d4871: Scheduling FlushMRSOp(500941768b6f491d9d3b82001870c17f): perf score=1.000000
I20260812 06:19:34.021395 27736 maintenance_manager.cc:643] P a0e34134d1f747f4857d47e9197d4871: FlushMRSOp(500941768b6f491d9d3b82001870c17f) complete. Timing: real 0.054s	user 0.028s	sys 0.004s Metrics: {"bytes_written":1275443,"cfile_init":1,"dirs.queue_time_us":105,"dirs.run_cpu_time_us":239,"dirs.run_wall_time_us":1455,"drs_written":1,"lbm_read_time_us":43,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2366,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:34.022151 27847 maintenance_manager.cc:419] P a0e34134d1f747f4857d47e9197d4871: Scheduling LogGCOp(500941768b6f491d9d3b82001870c17f): free 121006430 bytes of WAL
I20260812 06:19:34.022423 27736 log_reader.cc:385] T 500941768b6f491d9d3b82001870c17f: removed 12 log segments from log reader
I20260812 06:19:34.022486 27736 log.cc:1079] T 500941768b6f491d9d3b82001870c17f P a0e34134d1f747f4857d47e9197d4871: Deleting log segment in path: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566024816-27206-0/minicluster-data/ts-0-root/wals/500941768b6f491d9d3b82001870c17f/wal-000000003 (ops 12-16)
I20260812 06:19:34.022588 27736 log.cc:1079] T 500941768b6f491d9d3b82001870c17f P a0e34134d1f747f4857d47e9197d4871: Deleting log segment in path: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566024816-27206-0/minicluster-data/ts-0-root/wals/500941768b6f491d9d3b82001870c17f/wal-000000004 (ops 17-21)
I20260812 06:19:34.022658 27736 log.cc:1079] T 500941768b6f491d9d3b82001870c17f P a0e34134d1f747f4857d47e9197d4871: Deleting log segment in path: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566024816-27206-0/minicluster-data/ts-0-root/wals/500941768b6f491d9d3b82001870c17f/wal-000000005 (ops 22-26)
I20260812 06:19:34.022727 27736 log.cc:1079] T 500941768b6f491d9d3b82001870c17f P a0e34134d1f747f4857d47e9197d4871: Deleting log segment in path: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566024816-27206-0/minicluster-data/ts-0-root/wals/500941768b6f491d9d3b82001870c17f/wal-000000006 (ops 27-31)
I20260812 06:19:34.022774 27736 log.cc:1079] T 500941768b6f491d9d3b82001870c17f P a0e34134d1f747f4857d47e9197d4871: Deleting log segment in path: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566024816-27206-0/minicluster-data/ts-0-root/wals/500941768b6f491d9d3b82001870c17f/wal-000000007 (ops 32-36)
I20260812 06:19:34.022817 27736 log.cc:1079] T 500941768b6f491d9d3b82001870c17f P a0e34134d1f747f4857d47e9197d4871: Deleting log segment in path: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566024816-27206-0/minicluster-data/ts-0-root/wals/500941768b6f491d9d3b82001870c17f/wal-000000008 (ops 37-41)
I20260812 06:19:34.022861 27736 log.cc:1079] T 500941768b6f491d9d3b82001870c17f P a0e34134d1f747f4857d47e9197d4871: Deleting log segment in path: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566024816-27206-0/minicluster-data/ts-0-root/wals/500941768b6f491d9d3b82001870c17f/wal-000000009 (ops 42-46)
I20260812 06:19:34.022902 27736 log.cc:1079] T 500941768b6f491d9d3b82001870c17f P a0e34134d1f747f4857d47e9197d4871: Deleting log segment in path: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566024816-27206-0/minicluster-data/ts-0-root/wals/500941768b6f491d9d3b82001870c17f/wal-000000010 (ops 47-50)
I20260812 06:19:34.022945 27736 log.cc:1079] T 500941768b6f491d9d3b82001870c17f P a0e34134d1f747f4857d47e9197d4871: Deleting log segment in path: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566024816-27206-0/minicluster-data/ts-0-root/wals/500941768b6f491d9d3b82001870c17f/wal-000000011 (ops 51-55)
I20260812 06:19:34.022997 27736 log.cc:1079] T 500941768b6f491d9d3b82001870c17f P a0e34134d1f747f4857d47e9197d4871: Deleting log segment in path: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566024816-27206-0/minicluster-data/ts-0-root/wals/500941768b6f491d9d3b82001870c17f/wal-000000012 (ops 56-60)
I20260812 06:19:34.023038 27736 log.cc:1079] T 500941768b6f491d9d3b82001870c17f P a0e34134d1f747f4857d47e9197d4871: Deleting log segment in path: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566024816-27206-0/minicluster-data/ts-0-root/wals/500941768b6f491d9d3b82001870c17f/wal-000000013 (ops 61-65)
I20260812 06:19:34.023078 27736 log.cc:1079] T 500941768b6f491d9d3b82001870c17f P a0e34134d1f747f4857d47e9197d4871: Deleting log segment in path: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566024816-27206-0/minicluster-data/ts-0-root/wals/500941768b6f491d9d3b82001870c17f/wal-000000014 (ops 66-70)
I20260812 06:19:34.050257 27736 maintenance_manager.cc:643] P a0e34134d1f747f4857d47e9197d4871: LogGCOp(500941768b6f491d9d3b82001870c17f) complete. Timing: real 0.028s	user 0.001s	sys 0.023s Metrics: {}
I20260812 06:19:34.050746 27847 maintenance_manager.cc:419] P a0e34134d1f747f4857d47e9197d4871: Scheduling UndoDeltaBlockGCOp(500941768b6f491d9d3b82001870c17f): 482 bytes on disk
I20260812 06:19:34.051378 27736 maintenance_manager.cc:643] P a0e34134d1f747f4857d47e9197d4871: UndoDeltaBlockGCOp(500941768b6f491d9d3b82001870c17f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":110,"lbm_reads_lt_1ms":4}
I20260812 06:19:34.051884 27847 maintenance_manager.cc:419] P a0e34134d1f747f4857d47e9197d4871: Scheduling FlushDeltaMemStoresOp(500941768b6f491d9d3b82001870c17f): perf score=6.157687
I20260812 06:19:34.078840 27736 maintenance_manager.cc:643] P a0e34134d1f747f4857d47e9197d4871: FlushDeltaMemStoresOp(500941768b6f491d9d3b82001870c17f) complete. Timing: real 0.027s	user 0.014s	sys 0.012s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":11517,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:19:34.079376 27847 maintenance_manager.cc:419] P a0e34134d1f747f4857d47e9197d4871: Scheduling LogGCOp(500941768b6f491d9d3b82001870c17f): free 11564875 bytes of WAL
I20260812 06:19:34.079603 27736 log_reader.cc:385] T 500941768b6f491d9d3b82001870c17f: removed 1 log segments from log reader
I20260812 06:19:34.079649 27736 log.cc:1079] T 500941768b6f491d9d3b82001870c17f P a0e34134d1f747f4857d47e9197d4871: Deleting log segment in path: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566024816-27206-0/minicluster-data/ts-0-root/wals/500941768b6f491d9d3b82001870c17f/wal-000000015 (ops 71-74)
I20260812 06:19:34.082451 27736 maintenance_manager.cc:643] P a0e34134d1f747f4857d47e9197d4871: LogGCOp(500941768b6f491d9d3b82001870c17f) complete. Timing: real 0.003s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:19:34.082871 27847 maintenance_manager.cc:419] P a0e34134d1f747f4857d47e9197d4871: Scheduling FlushDeltaMemStoresOp(500941768b6f491d9d3b82001870c17f): perf score=2.188937
I20260812 06:19:34.103868 27736 maintenance_manager.cc:643] P a0e34134d1f747f4857d47e9197d4871: FlushDeltaMemStoresOp(500941768b6f491d9d3b82001870c17f) complete. Timing: real 0.021s	user 0.010s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6674,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:34.104642 27847 maintenance_manager.cc:419] P a0e34134d1f747f4857d47e9197d4871: Scheduling MajorDeltaCompactionOp(500941768b6f491d9d3b82001870c17f): perf score=1.000000
I20260812 06:19:34.306818 27736 maintenance_manager.cc:643] P a0e34134d1f747f4857d47e9197d4871: MajorDeltaCompactionOp(500941768b6f491d9d3b82001870c17f) complete. Timing: real 0.202s	user 0.142s	sys 0.059s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877221,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":789,"lbm_read_time_us":13591,"lbm_reads_lt_1ms":665,"lbm_write_time_us":39427,"lbm_writes_lt_1ms":643,"mutex_wait_us":557,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3200,"thread_start_us":91,"threads_started":1,"update_count":3000}
I20260812 06:19:34.307574 27847 maintenance_manager.cc:419] P a0e34134d1f747f4857d47e9197d4871: Scheduling FlushDeltaMemStoresOp(500941768b6f491d9d3b82001870c17f): perf score=14.095187
I20260812 06:19:34.365217 27736 maintenance_manager.cc:643] P a0e34134d1f747f4857d47e9197d4871: FlushDeltaMemStoresOp(500941768b6f491d9d3b82001870c17f) complete. Timing: real 0.057s	user 0.039s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":25648,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:34.366750 27847 maintenance_manager.cc:419] P a0e34134d1f747f4857d47e9197d4871: Scheduling FlushDeltaMemStoresOp(500941768b6f491d9d3b82001870c17f): perf score=2.188937
I20260812 06:19:34.387943 27736 maintenance_manager.cc:643] P a0e34134d1f747f4857d47e9197d4871: FlushDeltaMemStoresOp(500941768b6f491d9d3b82001870c17f) complete. Timing: real 0.021s	user 0.011s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":8040,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:34.388811 27847 maintenance_manager.cc:419] P a0e34134d1f747f4857d47e9197d4871: Scheduling MajorDeltaCompactionOp(500941768b6f491d9d3b82001870c17f): perf score=1.000000
I20260812 06:19:34.567224 27736 maintenance_manager.cc:643] P a0e34134d1f747f4857d47e9197d4871: MajorDeltaCompactionOp(500941768b6f491d9d3b82001870c17f) complete. Timing: real 0.178s	user 0.134s	sys 0.037s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":247,"lbm_read_time_us":11534,"lbm_reads_lt_1ms":568,"lbm_write_time_us":34013,"lbm_writes_lt_1ms":543,"mutex_wait_us":76,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2500}
I20260812 06:19:34.569171 27847 maintenance_manager.cc:419] P a0e34134d1f747f4857d47e9197d4871: Scheduling FlushDeltaMemStoresOp(500941768b6f491d9d3b82001870c17f): perf score=12.110812
I20260812 06:19:34.627363 27736 maintenance_manager.cc:643] P a0e34134d1f747f4857d47e9197d4871: FlushDeltaMemStoresOp(500941768b6f491d9d3b82001870c17f) complete. Timing: real 0.058s	user 0.035s	sys 0.020s Metrics: {"bytes_written":13661281,"delete_count":0,"lbm_write_time_us":25204,"lbm_writes_lt_1ms":336,"reinsert_count":0,"update_count":1665}
I20260812 06:19:34.627926 27847 maintenance_manager.cc:419] P a0e34134d1f747f4857d47e9197d4871: Scheduling FlushDeltaMemStoresOp(500941768b6f491d9d3b82001870c17f): perf score=1.196750
I20260812 06:19:34.648651 27736 maintenance_manager.cc:643] P a0e34134d1f747f4857d47e9197d4871: FlushDeltaMemStoresOp(500941768b6f491d9d3b82001870c17f) complete. Timing: real 0.021s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3159084,"delete_count":0,"lbm_write_time_us":3509,"lbm_writes_lt_1ms":80,"reinsert_count":0,"update_count":385}
I20260812 06:19:34.649153 27847 maintenance_manager.cc:419] P a0e34134d1f747f4857d47e9197d4871: Scheduling FlushDeltaMemStoresOp(500941768b6f491d9d3b82001870c17f): perf score=2.188937
I20260812 06:19:34.660077 27736 maintenance_manager.cc:643] P a0e34134d1f747f4857d47e9197d4871: FlushDeltaMemStoresOp(500941768b6f491d9d3b82001870c17f) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4146,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:34.660539 27847 maintenance_manager.cc:419] P a0e34134d1f747f4857d47e9197d4871: Scheduling MajorDeltaCompactionOp(500941768b6f491d9d3b82001870c17f): perf score=1.000000
I20260812 06:19:34.843413 27736 maintenance_manager.cc:643] P a0e34134d1f747f4857d47e9197d4871: MajorDeltaCompactionOp(500941768b6f491d9d3b82001870c17f) complete. Timing: real 0.183s	user 0.122s	sys 0.059s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774770,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":984,"lbm_read_time_us":13132,"lbm_reads_lt_1ms":573,"lbm_write_time_us":31515,"lbm_writes_lt_1ms":543,"mutex_wait_us":54,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11264,"update_count":2500}
I20260812 06:19:34.844091 27847 maintenance_manager.cc:419] P a0e34134d1f747f4857d47e9197d4871: Scheduling FlushDeltaMemStoresOp(500941768b6f491d9d3b82001870c17f): perf score=14.095187
I20260812 06:19:34.902302 27736 maintenance_manager.cc:643] P a0e34134d1f747f4857d47e9197d4871: FlushDeltaMemStoresOp(500941768b6f491d9d3b82001870c17f) complete. Timing: real 0.058s	user 0.033s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24713,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:34.902943 27847 maintenance_manager.cc:419] P a0e34134d1f747f4857d47e9197d4871: Scheduling FlushDeltaMemStoresOp(500941768b6f491d9d3b82001870c17f): perf score=2.188937
I20260812 06:19:34.916553 27736 maintenance_manager.cc:643] P a0e34134d1f747f4857d47e9197d4871: FlushDeltaMemStoresOp(500941768b6f491d9d3b82001870c17f) complete. Timing: real 0.013s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5413,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:34.917358 27847 maintenance_manager.cc:419] P a0e34134d1f747f4857d47e9197d4871: Scheduling MajorDeltaCompactionOp(500941768b6f491d9d3b82001870c17f): perf score=1.000000
I20260812 06:19:35.102186 27736 maintenance_manager.cc:643] P a0e34134d1f747f4857d47e9197d4871: MajorDeltaCompactionOp(500941768b6f491d9d3b82001870c17f) complete. Timing: real 0.185s	user 0.115s	sys 0.065s 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":4468,"lbm_read_time_us":14465,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30204,"lbm_writes_lt_1ms":543,"mutex_wait_us":3597,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":2500}
I20260812 06:19:35.102806 27847 maintenance_manager.cc:419] P a0e34134d1f747f4857d47e9197d4871: Scheduling FlushDeltaMemStoresOp(500941768b6f491d9d3b82001870c17f): perf score=14.095187
I20260812 06:19:35.160246 27736 maintenance_manager.cc:643] P a0e34134d1f747f4857d47e9197d4871: FlushDeltaMemStoresOp(500941768b6f491d9d3b82001870c17f) complete. Timing: real 0.057s	user 0.022s	sys 0.033s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":21712,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:35.160822 27847 maintenance_manager.cc:419] P a0e34134d1f747f4857d47e9197d4871: Scheduling FlushDeltaMemStoresOp(500941768b6f491d9d3b82001870c17f): perf score=2.188937
I20260812 06:19:35.171612 27736 maintenance_manager.cc:643] P a0e34134d1f747f4857d47e9197d4871: FlushDeltaMemStoresOp(500941768b6f491d9d3b82001870c17f) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4157,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:35.172096 27847 maintenance_manager.cc:419] P a0e34134d1f747f4857d47e9197d4871: Scheduling MajorDeltaCompactionOp(500941768b6f491d9d3b82001870c17f): perf score=1.000000
I20260812 06:19:35.367362 27736 maintenance_manager.cc:643] P a0e34134d1f747f4857d47e9197d4871: MajorDeltaCompactionOp(500941768b6f491d9d3b82001870c17f) complete. Timing: real 0.195s	user 0.141s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":242,"lbm_read_time_us":13432,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32387,"lbm_writes_lt_1ms":543,"mutex_wait_us":76,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":177792,"update_count":2500}
I20260812 06:19:35.368357 27847 maintenance_manager.cc:419] P a0e34134d1f747f4857d47e9197d4871: Scheduling FlushDeltaMemStoresOp(500941768b6f491d9d3b82001870c17f): perf score=14.095187
I20260812 06:19:35.427615 27736 maintenance_manager.cc:643] P a0e34134d1f747f4857d47e9197d4871: FlushDeltaMemStoresOp(500941768b6f491d9d3b82001870c17f) complete. Timing: real 0.059s	user 0.015s	sys 0.043s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":24135,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:35.428171 27847 maintenance_manager.cc:419] P a0e34134d1f747f4857d47e9197d4871: Scheduling FlushDeltaMemStoresOp(500941768b6f491d9d3b82001870c17f): perf score=2.188937
I20260812 06:19:35.439595 27736 maintenance_manager.cc:643] P a0e34134d1f747f4857d47e9197d4871: FlushDeltaMemStoresOp(500941768b6f491d9d3b82001870c17f) complete. Timing: real 0.011s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4481,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:35.440057 27847 maintenance_manager.cc:419] P a0e34134d1f747f4857d47e9197d4871: Scheduling MajorDeltaCompactionOp(500941768b6f491d9d3b82001870c17f): perf score=1.000000
I20260812 06:19:35.620813 27736 maintenance_manager.cc:643] P a0e34134d1f747f4857d47e9197d4871: MajorDeltaCompactionOp(500941768b6f491d9d3b82001870c17f) complete. Timing: real 0.181s	user 0.114s	sys 0.063s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":176,"lbm_read_time_us":12509,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29138,"lbm_writes_lt_1ms":543,"mutex_wait_us":24,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:35.621524 27847 maintenance_manager.cc:419] P a0e34134d1f747f4857d47e9197d4871: Scheduling FlushDeltaMemStoresOp(500941768b6f491d9d3b82001870c17f): perf score=14.095187
I20260812 06:19:35.681185 27736 maintenance_manager.cc:643] P a0e34134d1f747f4857d47e9197d4871: FlushDeltaMemStoresOp(500941768b6f491d9d3b82001870c17f) complete. Timing: real 0.060s	user 0.032s	sys 0.025s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":28072,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:35.681808 27847 maintenance_manager.cc:419] P a0e34134d1f747f4857d47e9197d4871: Scheduling FlushDeltaMemStoresOp(500941768b6f491d9d3b82001870c17f): perf score=2.188937
I20260812 06:19:35.716854 27736 maintenance_manager.cc:643] P a0e34134d1f747f4857d47e9197d4871: FlushDeltaMemStoresOp(500941768b6f491d9d3b82001870c17f) complete. Timing: real 0.035s	user 0.010s	sys 0.015s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5715,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:35.717578 27847 maintenance_manager.cc:419] P a0e34134d1f747f4857d47e9197d4871: Scheduling FlushMRSOp(500941768b6f491d9d3b82001870c17f): perf score=1.000000
I20260812 06:19:35.762405 27736 maintenance_manager.cc:643] P a0e34134d1f747f4857d47e9197d4871: FlushMRSOp(500941768b6f491d9d3b82001870c17f) complete. Timing: real 0.045s	user 0.032s	sys 0.000s Metrics: {"bytes_written":1357579,"cfile_init":1,"dirs.queue_time_us":68,"dirs.run_cpu_time_us":316,"dirs.run_wall_time_us":1754,"drs_written":1,"lbm_read_time_us":44,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2042,"lbm_writes_lt_1ms":44,"peak_mem_usage":0,"rows_written":33}
I20260812 06:19:35.763249 27847 maintenance_manager.cc:419] P a0e34134d1f747f4857d47e9197d4871: Scheduling LogGCOp(500941768b6f491d9d3b82001870c17f): free 121006461 bytes of WAL
I20260812 06:19:35.763518 27736 log_reader.cc:385] T 500941768b6f491d9d3b82001870c17f: removed 12 log segments from log reader
I20260812 06:19:35.763566 27736 log.cc:1079] T 500941768b6f491d9d3b82001870c17f P a0e34134d1f747f4857d47e9197d4871: Deleting log segment in path: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566024816-27206-0/minicluster-data/ts-0-root/wals/500941768b6f491d9d3b82001870c17f/wal-000000016 (ops 75-79)
I20260812 06:19:35.763600 27736 log.cc:1079] T 500941768b6f491d9d3b82001870c17f P a0e34134d1f747f4857d47e9197d4871: Deleting log segment in path: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566024816-27206-0/minicluster-data/ts-0-root/wals/500941768b6f491d9d3b82001870c17f/wal-000000017 (ops 80-84)
I20260812 06:19:35.763646 27736 log.cc:1079] T 500941768b6f491d9d3b82001870c17f P a0e34134d1f747f4857d47e9197d4871: Deleting log segment in path: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566024816-27206-0/minicluster-data/ts-0-root/wals/500941768b6f491d9d3b82001870c17f/wal-000000018 (ops 85-89)
I20260812 06:19:35.763734 27736 log.cc:1079] T 500941768b6f491d9d3b82001870c17f P a0e34134d1f747f4857d47e9197d4871: Deleting log segment in path: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566024816-27206-0/minicluster-data/ts-0-root/wals/500941768b6f491d9d3b82001870c17f/wal-000000019 (ops 90-94)
I20260812 06:19:35.763756 27736 log.cc:1079] T 500941768b6f491d9d3b82001870c17f P a0e34134d1f747f4857d47e9197d4871: Deleting log segment in path: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566024816-27206-0/minicluster-data/ts-0-root/wals/500941768b6f491d9d3b82001870c17f/wal-000000020 (ops 95-98)
I20260812 06:19:35.763772 27736 log.cc:1079] T 500941768b6f491d9d3b82001870c17f P a0e34134d1f747f4857d47e9197d4871: Deleting log segment in path: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566024816-27206-0/minicluster-data/ts-0-root/wals/500941768b6f491d9d3b82001870c17f/wal-000000021 (ops 99-103)
I20260812 06:19:35.763789 27736 log.cc:1079] T 500941768b6f491d9d3b82001870c17f P a0e34134d1f747f4857d47e9197d4871: Deleting log segment in path: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566024816-27206-0/minicluster-data/ts-0-root/wals/500941768b6f491d9d3b82001870c17f/wal-000000022 (ops 104-108)
I20260812 06:19:35.763805 27736 log.cc:1079] T 500941768b6f491d9d3b82001870c17f P a0e34134d1f747f4857d47e9197d4871: Deleting log segment in path: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566024816-27206-0/minicluster-data/ts-0-root/wals/500941768b6f491d9d3b82001870c17f/wal-000000023 (ops 109-113)
I20260812 06:19:35.763823 27736 log.cc:1079] T 500941768b6f491d9d3b82001870c17f P a0e34134d1f747f4857d47e9197d4871: Deleting log segment in path: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566024816-27206-0/minicluster-data/ts-0-root/wals/500941768b6f491d9d3b82001870c17f/wal-000000024 (ops 114-118)
I20260812 06:19:35.763839 27736 log.cc:1079] T 500941768b6f491d9d3b82001870c17f P a0e34134d1f747f4857d47e9197d4871: Deleting log segment in path: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566024816-27206-0/minicluster-data/ts-0-root/wals/500941768b6f491d9d3b82001870c17f/wal-000000025 (ops 119-123)
I20260812 06:19:35.763856 27736 log.cc:1079] T 500941768b6f491d9d3b82001870c17f P a0e34134d1f747f4857d47e9197d4871: Deleting log segment in path: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566024816-27206-0/minicluster-data/ts-0-root/wals/500941768b6f491d9d3b82001870c17f/wal-000000026 (ops 124-128)
I20260812 06:19:35.763872 27736 log.cc:1079] T 500941768b6f491d9d3b82001870c17f P a0e34134d1f747f4857d47e9197d4871: Deleting log segment in path: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566024816-27206-0/minicluster-data/ts-0-root/wals/500941768b6f491d9d3b82001870c17f/wal-000000027 (ops 129-133)
I20260812 06:19:35.791083 27736 maintenance_manager.cc:643] P a0e34134d1f747f4857d47e9197d4871: LogGCOp(500941768b6f491d9d3b82001870c17f) complete. Timing: real 0.028s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:19:35.791646 27847 maintenance_manager.cc:419] P a0e34134d1f747f4857d47e9197d4871: Scheduling FlushDeltaMemStoresOp(500941768b6f491d9d3b82001870c17f): perf score=6.157687
I20260812 06:19:35.825239 27736 maintenance_manager.cc:643] P a0e34134d1f747f4857d47e9197d4871: FlushDeltaMemStoresOp(500941768b6f491d9d3b82001870c17f) complete. Timing: real 0.033s	user 0.025s	sys 0.004s Metrics: {"bytes_written":8205077,"delete_count":0,"lbm_write_time_us":13816,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:19:35.825699 27847 maintenance_manager.cc:419] P a0e34134d1f747f4857d47e9197d4871: Scheduling LogGCOp(500941768b6f491d9d3b82001870c17f): free 12017954 bytes of WAL
I20260812 06:19:35.825902 27736 log_reader.cc:385] T 500941768b6f491d9d3b82001870c17f: removed 1 log segments from log reader
I20260812 06:19:35.825945 27736 log.cc:1079] T 500941768b6f491d9d3b82001870c17f P a0e34134d1f747f4857d47e9197d4871: Deleting log segment in path: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566024816-27206-0/minicluster-data/ts-0-root/wals/500941768b6f491d9d3b82001870c17f/wal-000000028 (ops 134-138)
I20260812 06:19:35.828857 27736 maintenance_manager.cc:643] P a0e34134d1f747f4857d47e9197d4871: LogGCOp(500941768b6f491d9d3b82001870c17f) complete. Timing: real 0.003s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:19:35.829237 27847 maintenance_manager.cc:419] P a0e34134d1f747f4857d47e9197d4871: Scheduling MajorDeltaCompactionOp(500941768b6f491d9d3b82001870c17f): perf score=1.000000
I20260812 06:19:36.078698 27736 maintenance_manager.cc:643] P a0e34134d1f747f4857d47e9197d4871: MajorDeltaCompactionOp(500941768b6f491d9d3b82001870c17f) complete. Timing: real 0.249s	user 0.152s	sys 0.097s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":32979633,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":403,"lbm_read_time_us":16633,"lbm_reads_lt_1ms":765,"lbm_write_time_us":44123,"lbm_writes_lt_1ms":743,"mutex_wait_us":75,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":12928,"thread_start_us":90,"threads_started":1,"update_count":3500}
I20260812 06:19:36.079772 27847 maintenance_manager.cc:419] P a0e34134d1f747f4857d47e9197d4871: Scheduling FlushDeltaMemStoresOp(500941768b6f491d9d3b82001870c17f): perf score=18.063937
I20260812 06:19:36.140267 27736 maintenance_manager.cc:643] P a0e34134d1f747f4857d47e9197d4871: FlushDeltaMemStoresOp(500941768b6f491d9d3b82001870c17f) complete. Timing: real 0.060s	user 0.043s	sys 0.015s Metrics: {"bytes_written":20512323,"delete_count":0,"lbm_write_time_us":27550,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:36.140880 27847 maintenance_manager.cc:419] P a0e34134d1f747f4857d47e9197d4871: Scheduling FlushDeltaMemStoresOp(500941768b6f491d9d3b82001870c17f): perf score=2.188937
I20260812 06:19:36.152559 27736 maintenance_manager.cc:643] P a0e34134d1f747f4857d47e9197d4871: FlushDeltaMemStoresOp(500941768b6f491d9d3b82001870c17f) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4325,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:36.153200 27847 maintenance_manager.cc:419] P a0e34134d1f747f4857d47e9197d4871: Scheduling MajorDeltaCompactionOp(500941768b6f491d9d3b82001870c17f): perf score=1.000000
I20260812 06:19:36.371738 27736 maintenance_manager.cc:643] P a0e34134d1f747f4857d47e9197d4871: MajorDeltaCompactionOp(500941768b6f491d9d3b82001870c17f) complete. Timing: real 0.218s	user 0.139s	sys 0.079s 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":1231,"lbm_read_time_us":15664,"lbm_reads_lt_1ms":672,"lbm_write_time_us":35630,"lbm_writes_lt_1ms":643,"mutex_wait_us":340,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":36480,"update_count":3000}
I20260812 06:19:36.372504 27847 maintenance_manager.cc:419] P a0e34134d1f747f4857d47e9197d4871: Scheduling UndoDeltaBlockGCOp(500941768b6f491d9d3b82001870c17f): 508 bytes on disk
I20260812 06:19:36.372980 27736 maintenance_manager.cc:643] P a0e34134d1f747f4857d47e9197d4871: UndoDeltaBlockGCOp(500941768b6f491d9d3b82001870c17f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":45,"lbm_reads_lt_1ms":4}
I20260812 06:19:36.373824 27847 maintenance_manager.cc:419] P a0e34134d1f747f4857d47e9197d4871: Scheduling FlushDeltaMemStoresOp(500941768b6f491d9d3b82001870c17f): perf score=14.095187
I20260812 06:19:36.427076 27736 maintenance_manager.cc:643] P a0e34134d1f747f4857d47e9197d4871: FlushDeltaMemStoresOp(500941768b6f491d9d3b82001870c17f) complete. Timing: real 0.053s	user 0.040s	sys 0.007s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":21292,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:36.427682 27847 maintenance_manager.cc:419] P a0e34134d1f747f4857d47e9197d4871: Scheduling FlushDeltaMemStoresOp(500941768b6f491d9d3b82001870c17f): perf score=2.188937
I20260812 06:19:36.441855 27736 maintenance_manager.cc:643] P a0e34134d1f747f4857d47e9197d4871: FlushDeltaMemStoresOp(500941768b6f491d9d3b82001870c17f) complete. Timing: real 0.014s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4878,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:36.442804 27847 maintenance_manager.cc:419] P a0e34134d1f747f4857d47e9197d4871: Scheduling MajorDeltaCompactionOp(500941768b6f491d9d3b82001870c17f): perf score=1.000000
I20260812 06:19:36.630496 27736 maintenance_manager.cc:643] P a0e34134d1f747f4857d47e9197d4871: MajorDeltaCompactionOp(500941768b6f491d9d3b82001870c17f) complete. Timing: real 0.187s	user 0.142s	sys 0.045s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774691,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":942,"lbm_read_time_us":12891,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30644,"lbm_writes_lt_1ms":543,"mutex_wait_us":282,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10752,"update_count":2500}
I20260812 06:19:36.631188 27847 maintenance_manager.cc:419] P a0e34134d1f747f4857d47e9197d4871: Scheduling FlushDeltaMemStoresOp(500941768b6f491d9d3b82001870c17f): perf score=14.095187
I20260812 06:19:36.688952 27736 maintenance_manager.cc:643] P a0e34134d1f747f4857d47e9197d4871: FlushDeltaMemStoresOp(500941768b6f491d9d3b82001870c17f) complete. Timing: real 0.057s	user 0.036s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24983,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:36.689623 27847 maintenance_manager.cc:419] P a0e34134d1f747f4857d47e9197d4871: Scheduling FlushDeltaMemStoresOp(500941768b6f491d9d3b82001870c17f): perf score=2.188937
I20260812 06:19:36.701188 27736 maintenance_manager.cc:643] P a0e34134d1f747f4857d47e9197d4871: FlushDeltaMemStoresOp(500941768b6f491d9d3b82001870c17f) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4146,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:36.701678 27847 maintenance_manager.cc:419] P a0e34134d1f747f4857d47e9197d4871: Scheduling MajorDeltaCompactionOp(500941768b6f491d9d3b82001870c17f): perf score=1.000000
I20260812 06:19:36.899140 27736 maintenance_manager.cc:643] P a0e34134d1f747f4857d47e9197d4871: MajorDeltaCompactionOp(500941768b6f491d9d3b82001870c17f) complete. Timing: real 0.197s	user 0.130s	sys 0.065s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1647,"lbm_read_time_us":14142,"lbm_reads_lt_1ms":572,"lbm_write_time_us":35934,"lbm_writes_lt_1ms":543,"mutex_wait_us":559,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":25088,"update_count":2500}
I20260812 06:19:36.899763 27847 maintenance_manager.cc:419] P a0e34134d1f747f4857d47e9197d4871: Scheduling FlushDeltaMemStoresOp(500941768b6f491d9d3b82001870c17f): perf score=14.095187
I20260812 06:19:36.964561 27736 maintenance_manager.cc:643] P a0e34134d1f747f4857d47e9197d4871: FlushDeltaMemStoresOp(500941768b6f491d9d3b82001870c17f) complete. Timing: real 0.065s	user 0.024s	sys 0.035s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":23403,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:36.965246 27847 maintenance_manager.cc:419] P a0e34134d1f747f4857d47e9197d4871: Scheduling FlushDeltaMemStoresOp(500941768b6f491d9d3b82001870c17f): perf score=2.188937
I20260812 06:19:36.979279 27736 maintenance_manager.cc:643] P a0e34134d1f747f4857d47e9197d4871: FlushDeltaMemStoresOp(500941768b6f491d9d3b82001870c17f) complete. Timing: real 0.014s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5667,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:36.979882 27847 maintenance_manager.cc:419] P a0e34134d1f747f4857d47e9197d4871: Scheduling MajorDeltaCompactionOp(500941768b6f491d9d3b82001870c17f): perf score=1.000000
I20260812 06:19:37.156626 27736 maintenance_manager.cc:643] P a0e34134d1f747f4857d47e9197d4871: MajorDeltaCompactionOp(500941768b6f491d9d3b82001870c17f) complete. Timing: real 0.176s	user 0.135s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":215,"lbm_read_time_us":13997,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30161,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:19:37.157423 27847 maintenance_manager.cc:419] P a0e34134d1f747f4857d47e9197d4871: Scheduling FlushDeltaMemStoresOp(500941768b6f491d9d3b82001870c17f): perf score=10.126437
I20260812 06:19:37.201977 27736 maintenance_manager.cc:643] P a0e34134d1f747f4857d47e9197d4871: FlushDeltaMemStoresOp(500941768b6f491d9d3b82001870c17f) complete. Timing: real 0.044s	user 0.025s	sys 0.016s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":19623,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:37.202889 27847 maintenance_manager.cc:419] P a0e34134d1f747f4857d47e9197d4871: Scheduling FlushDeltaMemStoresOp(500941768b6f491d9d3b82001870c17f): perf score=2.188937
I20260812 06:19:37.221282 27736 maintenance_manager.cc:643] P a0e34134d1f747f4857d47e9197d4871: FlushDeltaMemStoresOp(500941768b6f491d9d3b82001870c17f) complete. Timing: real 0.018s	user 0.011s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6709,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:37.222790 27847 maintenance_manager.cc:419] P a0e34134d1f747f4857d47e9197d4871: Scheduling MajorDeltaCompactionOp(500941768b6f491d9d3b82001870c17f): perf score=1.000000
I20260812 06:19:37.376720 27736 maintenance_manager.cc:643] P a0e34134d1f747f4857d47e9197d4871: MajorDeltaCompactionOp(500941768b6f491d9d3b82001870c17f) complete. Timing: real 0.153s	user 0.096s	sys 0.056s 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":259,"lbm_read_time_us":11189,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27969,"lbm_writes_lt_1ms":443,"mutex_wait_us":56,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":18304,"update_count":2000}
I20260812 06:19:37.379786 27847 maintenance_manager.cc:419] P a0e34134d1f747f4857d47e9197d4871: Scheduling FlushDeltaMemStoresOp(500941768b6f491d9d3b82001870c17f): perf score=10.126437
I20260812 06:19:37.422982 27736 maintenance_manager.cc:643] P a0e34134d1f747f4857d47e9197d4871: FlushDeltaMemStoresOp(500941768b6f491d9d3b82001870c17f) complete. Timing: real 0.043s	user 0.022s	sys 0.021s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":18895,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:37.423738 27847 maintenance_manager.cc:419] P a0e34134d1f747f4857d47e9197d4871: Scheduling FlushDeltaMemStoresOp(500941768b6f491d9d3b82001870c17f): perf score=2.188937
I20260812 06:19:37.441790 27736 maintenance_manager.cc:643] P a0e34134d1f747f4857d47e9197d4871: FlushDeltaMemStoresOp(500941768b6f491d9d3b82001870c17f) complete. Timing: real 0.018s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6906,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:37.442361 27847 maintenance_manager.cc:419] P a0e34134d1f747f4857d47e9197d4871: Scheduling FlushMRSOp(500941768b6f491d9d3b82001870c17f): perf score=1.000000
I20260812 06:19:37.472114 27736 maintenance_manager.cc:643] P a0e34134d1f747f4857d47e9197d4871: FlushMRSOp(500941768b6f491d9d3b82001870c17f) complete. Timing: real 0.029s	user 0.027s	sys 0.001s Metrics: {"bytes_written":1234479,"cfile_init":1,"dirs.queue_time_us":89,"dirs.run_cpu_time_us":248,"dirs.run_wall_time_us":1171,"drs_written":1,"lbm_read_time_us":45,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1745,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:19:37.472765 27847 maintenance_manager.cc:419] P a0e34134d1f747f4857d47e9197d4871: Scheduling LogGCOp(500941768b6f491d9d3b82001870c17f): free 124710562 bytes of WAL
I20260812 06:19:37.473001 27736 log_reader.cc:385] T 500941768b6f491d9d3b82001870c17f: removed 12 log segments from log reader
I20260812 06:19:37.473043 27736 log.cc:1079] T 500941768b6f491d9d3b82001870c17f P a0e34134d1f747f4857d47e9197d4871: Deleting log segment in path: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566024816-27206-0/minicluster-data/ts-0-root/wals/500941768b6f491d9d3b82001870c17f/wal-000000029 (ops 139-143)
I20260812 06:19:37.473073 27736 log.cc:1079] T 500941768b6f491d9d3b82001870c17f P a0e34134d1f747f4857d47e9197d4871: Deleting log segment in path: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566024816-27206-0/minicluster-data/ts-0-root/wals/500941768b6f491d9d3b82001870c17f/wal-000000030 (ops 144-148)
I20260812 06:19:37.473136 27736 log.cc:1079] T 500941768b6f491d9d3b82001870c17f P a0e34134d1f747f4857d47e9197d4871: Deleting log segment in path: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566024816-27206-0/minicluster-data/ts-0-root/wals/500941768b6f491d9d3b82001870c17f/wal-000000031 (ops 149-153)
I20260812 06:19:37.473181 27736 log.cc:1079] T 500941768b6f491d9d3b82001870c17f P a0e34134d1f747f4857d47e9197d4871: Deleting log segment in path: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566024816-27206-0/minicluster-data/ts-0-root/wals/500941768b6f491d9d3b82001870c17f/wal-000000032 (ops 154-158)
I20260812 06:19:37.473240 27736 log.cc:1079] T 500941768b6f491d9d3b82001870c17f P a0e34134d1f747f4857d47e9197d4871: Deleting log segment in path: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566024816-27206-0/minicluster-data/ts-0-root/wals/500941768b6f491d9d3b82001870c17f/wal-000000033 (ops 159-163)
I20260812 06:19:37.473282 27736 log.cc:1079] T 500941768b6f491d9d3b82001870c17f P a0e34134d1f747f4857d47e9197d4871: Deleting log segment in path: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566024816-27206-0/minicluster-data/ts-0-root/wals/500941768b6f491d9d3b82001870c17f/wal-000000034 (ops 164-168)
I20260812 06:19:37.473351 27736 log.cc:1079] T 500941768b6f491d9d3b82001870c17f P a0e34134d1f747f4857d47e9197d4871: Deleting log segment in path: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566024816-27206-0/minicluster-data/ts-0-root/wals/500941768b6f491d9d3b82001870c17f/wal-000000035 (ops 169-173)
I20260812 06:19:37.473389 27736 log.cc:1079] T 500941768b6f491d9d3b82001870c17f P a0e34134d1f747f4857d47e9197d4871: Deleting log segment in path: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566024816-27206-0/minicluster-data/ts-0-root/wals/500941768b6f491d9d3b82001870c17f/wal-000000036 (ops 174-178)
I20260812 06:19:37.473431 27736 log.cc:1079] T 500941768b6f491d9d3b82001870c17f P a0e34134d1f747f4857d47e9197d4871: Deleting log segment in path: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566024816-27206-0/minicluster-data/ts-0-root/wals/500941768b6f491d9d3b82001870c17f/wal-000000037 (ops 179-183)
I20260812 06:19:37.473469 27736 log.cc:1079] T 500941768b6f491d9d3b82001870c17f P a0e34134d1f747f4857d47e9197d4871: Deleting log segment in path: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566024816-27206-0/minicluster-data/ts-0-root/wals/500941768b6f491d9d3b82001870c17f/wal-000000038 (ops 184-188)
I20260812 06:19:37.473506 27736 log.cc:1079] T 500941768b6f491d9d3b82001870c17f P a0e34134d1f747f4857d47e9197d4871: Deleting log segment in path: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566024816-27206-0/minicluster-data/ts-0-root/wals/500941768b6f491d9d3b82001870c17f/wal-000000039 (ops 189-193)
I20260812 06:19:37.473546 27736 log.cc:1079] T 500941768b6f491d9d3b82001870c17f P a0e34134d1f747f4857d47e9197d4871: Deleting log segment in path: /tmp/dist-test-taskFJx6Z5/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566024816-27206-0/minicluster-data/ts-0-root/wals/500941768b6f491d9d3b82001870c17f/wal-000000040 (ops 194-198)
I20260812 06:19:37.502007 27736 maintenance_manager.cc:643] P a0e34134d1f747f4857d47e9197d4871: LogGCOp(500941768b6f491d9d3b82001870c17f) complete. Timing: real 0.029s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:19:37.502638 27847 maintenance_manager.cc:419] P a0e34134d1f747f4857d47e9197d4871: Scheduling FlushDeltaMemStoresOp(500941768b6f491d9d3b82001870c17f): perf score=3.181125
I20260812 06:19:37.511130 27206 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.273s	user 1.884s	sys 0.208s
I20260812 06:19:37.514875 27736 maintenance_manager.cc:643] P a0e34134d1f747f4857d47e9197d4871: FlushDeltaMemStoresOp(500941768b6f491d9d3b82001870c17f) complete. Timing: real 0.012s	user 0.010s	sys 0.002s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":5194,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:37.515317 27847 maintenance_manager.cc:419] P a0e34134d1f747f4857d47e9197d4871: Scheduling FlushDeltaMemStoresOp(500941768b6f491d9d3b82001870c17f): perf score=2.188937
I20260812 06:19:37.526446 27736 maintenance_manager.cc:643] P a0e34134d1f747f4857d47e9197d4871: FlushDeltaMemStoresOp(500941768b6f491d9d3b82001870c17f) complete. Timing: real 0.011s	user 0.003s	sys 0.006s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4684,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:37.526929 27847 maintenance_manager.cc:419] P a0e34134d1f747f4857d47e9197d4871: Scheduling MajorDeltaCompactionOp(500941768b6f491d9d3b82001870c17f): perf score=1.000000
I20260812 06:19:37.572954 27206 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.061s	user 0.000s	sys 0.000s
I20260812 06:19:37.573488 27206 tablet_server.cc:179] TabletServer@127.26.145.129:0 shutting down...
I20260812 06:19:37.678228 27736 maintenance_manager.cc:643] P a0e34134d1f747f4857d47e9197d4871: MajorDeltaCompactionOp(500941768b6f491d9d3b82001870c17f) complete. Timing: real 0.151s	user 0.119s	sys 0.032s Metrics: {"cfile_cache_hit":302,"cfile_cache_hit_bytes":12308786,"cfile_cache_miss":332,"cfile_cache_miss_bytes":16568539,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1258,"lbm_read_time_us":6625,"lbm_reads_lt_1ms":368,"lbm_write_time_us":33143,"lbm_writes_lt_1ms":643,"mutex_wait_us":335,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":31488,"thread_start_us":89,"threads_started":1,"update_count":3000}
I20260812 06:19:37.679406 27206 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:37.679811 27206 tablet_replica.cc:333] T 500941768b6f491d9d3b82001870c17f P a0e34134d1f747f4857d47e9197d4871: stopping tablet replica
I20260812 06:19:37.680027 27206 raft_consensus.cc:2243] T 500941768b6f491d9d3b82001870c17f P a0e34134d1f747f4857d47e9197d4871 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:37.680285 27206 raft_consensus.cc:2272] T 500941768b6f491d9d3b82001870c17f P a0e34134d1f747f4857d47e9197d4871 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:37.686419 27206 tablet_server.cc:196] TabletServer@127.26.145.129:0 shutdown complete.
I20260812 06:19:37.730286 27206 master.cc:562] Master@127.26.145.190:42267 shutting down...
I20260812 06:19:37.735984 27206 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 24a40cbfaf9f408f87f4d1c4400a5738 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:37.736222 27206 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 24a40cbfaf9f408f87f4d1c4400a5738 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:37.736335 27206 tablet_replica.cc:333] T 00000000000000000000000000000000 P 24a40cbfaf9f408f87f4d1c4400a5738: stopping tablet replica
I20260812 06:19:37.749163 27206 master.cc:584] Master@127.26.145.190:42267 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5816 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11804 ms total)

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