[==========] 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:45.842073 21174 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.20.173.190:36395
I20260812 06:19:45.843127 21174 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:45.843775 21174 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:45.851167 21181 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:45.851325 21174 server_base.cc:1061] running on GCE node
W20260812 06:19:45.851176 21184 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:45.851442 21182 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:45.852047 21174 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:45.852162 21174 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:45.852208 21174 hybrid_clock.cc:648] HybridClock initialized: now 1786515585852206 us; error 0 us; skew 500 ppm
I20260812 06:19:45.854115 21174 webserver.cc:533] Webserver started at http://127.20.173.190:42013/ using document root <none> and password file <none>
I20260812 06:19:45.854714 21174 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:45.854784 21174 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:45.855027 21174 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:45.856748 21174 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585830708-21174-0/minicluster-data/master-0-root/instance:
uuid: "8d537737f0434cbea620dd33e6e6c49d"
format_stamp: "Formatted at 2026-08-12 06:19:45 on dist-test-slave-rmhg"
I20260812 06:19:45.860564 21174 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:19:45.862980 21190 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:45.864132 21174 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.000s	sys 0.001s
I20260812 06:19:45.864272 21174 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585830708-21174-0/minicluster-data/master-0-root
uuid: "8d537737f0434cbea620dd33e6e6c49d"
format_stamp: "Formatted at 2026-08-12 06:19:45 on dist-test-slave-rmhg"
I20260812 06:19:45.864382 21174 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585830708-21174-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585830708-21174-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585830708-21174-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:45.874032 21174 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:45.874697 21174 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:45.874859 21174 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:45.882791 21174 rpc_server.cc:307] RPC server started. Bound to: 127.20.173.190:36395
I20260812 06:19:45.882787 21270 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.20.173.190:36395 every 8 connection(s)
I20260812 06:19:45.885344 21271 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:45.891302 21271 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 8d537737f0434cbea620dd33e6e6c49d: Bootstrap starting.
I20260812 06:19:45.893716 21271 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 8d537737f0434cbea620dd33e6e6c49d: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:45.894634 21271 log.cc:826] T 00000000000000000000000000000000 P 8d537737f0434cbea620dd33e6e6c49d: Log is configured to *not* fsync() on all Append() calls
I20260812 06:19:45.896445 21271 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 8d537737f0434cbea620dd33e6e6c49d: No bootstrap required, opened a new log
I20260812 06:19:45.899390 21271 raft_consensus.cc:359] T 00000000000000000000000000000000 P 8d537737f0434cbea620dd33e6e6c49d [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8d537737f0434cbea620dd33e6e6c49d" member_type: VOTER }
I20260812 06:19:45.899574 21271 raft_consensus.cc:385] T 00000000000000000000000000000000 P 8d537737f0434cbea620dd33e6e6c49d [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:45.899623 21271 raft_consensus.cc:740] T 00000000000000000000000000000000 P 8d537737f0434cbea620dd33e6e6c49d [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 8d537737f0434cbea620dd33e6e6c49d, State: Initialized, Role: FOLLOWER
I20260812 06:19:45.900190 21271 consensus_queue.cc:260] T 00000000000000000000000000000000 P 8d537737f0434cbea620dd33e6e6c49d [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: "8d537737f0434cbea620dd33e6e6c49d" member_type: VOTER }
I20260812 06:19:45.900323 21271 raft_consensus.cc:399] T 00000000000000000000000000000000 P 8d537737f0434cbea620dd33e6e6c49d [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:45.900372 21271 raft_consensus.cc:493] T 00000000000000000000000000000000 P 8d537737f0434cbea620dd33e6e6c49d [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:45.900463 21271 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 8d537737f0434cbea620dd33e6e6c49d [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:45.901281 21271 raft_consensus.cc:515] T 00000000000000000000000000000000 P 8d537737f0434cbea620dd33e6e6c49d [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8d537737f0434cbea620dd33e6e6c49d" member_type: VOTER }
I20260812 06:19:45.901708 21271 leader_election.cc:304] T 00000000000000000000000000000000 P 8d537737f0434cbea620dd33e6e6c49d [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: 8d537737f0434cbea620dd33e6e6c49d; no voters: 
I20260812 06:19:45.902001 21271 leader_election.cc:290] T 00000000000000000000000000000000 P 8d537737f0434cbea620dd33e6e6c49d [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:45.902158 21276 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 8d537737f0434cbea620dd33e6e6c49d [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:45.902401 21276 raft_consensus.cc:697] T 00000000000000000000000000000000 P 8d537737f0434cbea620dd33e6e6c49d [term 1 LEADER]: Becoming Leader. State: Replica: 8d537737f0434cbea620dd33e6e6c49d, State: Running, Role: LEADER
I20260812 06:19:45.902848 21276 consensus_queue.cc:237] T 00000000000000000000000000000000 P 8d537737f0434cbea620dd33e6e6c49d [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: "8d537737f0434cbea620dd33e6e6c49d" member_type: VOTER }
I20260812 06:19:45.903017 21271 sys_catalog.cc:565] T 00000000000000000000000000000000 P 8d537737f0434cbea620dd33e6e6c49d [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:45.904858 21277 sys_catalog.cc:455] T 00000000000000000000000000000000 P 8d537737f0434cbea620dd33e6e6c49d [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "8d537737f0434cbea620dd33e6e6c49d" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8d537737f0434cbea620dd33e6e6c49d" member_type: VOTER } }
I20260812 06:19:45.904865 21279 sys_catalog.cc:455] T 00000000000000000000000000000000 P 8d537737f0434cbea620dd33e6e6c49d [sys.catalog]: SysCatalogTable state changed. Reason: New leader 8d537737f0434cbea620dd33e6e6c49d. Latest consensus state: current_term: 1 leader_uuid: "8d537737f0434cbea620dd33e6e6c49d" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8d537737f0434cbea620dd33e6e6c49d" member_type: VOTER } }
I20260812 06:19:45.904994 21279 sys_catalog.cc:458] T 00000000000000000000000000000000 P 8d537737f0434cbea620dd33e6e6c49d [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:45.904994 21277 sys_catalog.cc:458] T 00000000000000000000000000000000 P 8d537737f0434cbea620dd33e6e6c49d [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:45.905354 21174 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
W20260812 06:19:45.907256 21307 catalog_manager.cc:1594] T 00000000000000000000000000000000 P 8d537737f0434cbea620dd33e6e6c49d: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:19:45.907320 21307 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:19:45.907389 21305 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:45.908108 21305 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:45.912895 21305 catalog_manager.cc:1383] Generated new cluster ID: 96042c6dea544ab391519a391d61ac1f
I20260812 06:19:45.912961 21305 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:45.935043 21305 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:45.936316 21305 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:45.945523 21305 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 8d537737f0434cbea620dd33e6e6c49d: Generated new TSK 0
I20260812 06:19:45.946384 21305 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:45.970264 21174 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:45.973008 21317 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:45.973191 21315 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:45.973028 21314 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:45.973415 21174 server_base.cc:1061] running on GCE node
I20260812 06:19:45.973657 21174 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:45.973698 21174 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:45.973713 21174 hybrid_clock.cc:648] HybridClock initialized: now 1786515585973713 us; error 0 us; skew 500 ppm
I20260812 06:19:45.974586 21174 webserver.cc:533] Webserver started at http://127.20.173.129:45485/ using document root <none> and password file <none>
I20260812 06:19:45.974768 21174 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:45.974825 21174 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:45.974903 21174 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:45.975289 21174 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585830708-21174-0/minicluster-data/ts-0-root/instance:
uuid: "d714efdbf43f453b814f75bdb8c5402b"
format_stamp: "Formatted at 2026-08-12 06:19:45 on dist-test-slave-rmhg"
I20260812 06:19:45.976864 21174 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:45.977922 21327 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:45.978188 21174 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:45.978260 21174 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585830708-21174-0/minicluster-data/ts-0-root
uuid: "d714efdbf43f453b814f75bdb8c5402b"
format_stamp: "Formatted at 2026-08-12 06:19:45 on dist-test-slave-rmhg"
I20260812 06:19:45.978338 21174 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585830708-21174-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585830708-21174-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585830708-21174-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:45.984819 21174 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:45.985291 21174 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:45.985782 21174 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:45.986613 21174 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:45.986665 21174 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:45.986722 21174 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:45.986747 21174 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:45.993144 21174 rpc_server.cc:307] RPC server started. Bound to: 127.20.173.129:34521
I20260812 06:19:45.993214 21421 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.20.173.129:34521 every 8 connection(s)
I20260812 06:19:46.009636 21422 heartbeater.cc:344] Connected to a master server at 127.20.173.190:36395
I20260812 06:19:46.009900 21422 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:46.010363 21422 heartbeater.cc:507] Master 127.20.173.190:36395 requested a full tablet report, sending...
I20260812 06:19:46.011916 21213 ts_manager.cc:194] Registered new tserver with Master: d714efdbf43f453b814f75bdb8c5402b (127.20.173.129:34521)
I20260812 06:19:46.012714 21174 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.018890141s
I20260812 06:19:46.013477 21213 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:56256
I20260812 06:19:46.022162 21213 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:56264:
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:46.035990 21376 tablet_service.cc:1511] Processing CreateTablet for tablet f72a813222b74e73999298c72322a84c (DEFAULT_TABLE table=heavy-update-compaction-test [id=9140fc6f55454fe99f5cdeeb43a2b611]), partition=
I20260812 06:19:46.036427 21376 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet f72a813222b74e73999298c72322a84c. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:46.038830 21435 tablet_bootstrap.cc:492] T f72a813222b74e73999298c72322a84c P d714efdbf43f453b814f75bdb8c5402b: Bootstrap starting.
I20260812 06:19:46.039755 21435 tablet_bootstrap.cc:654] T f72a813222b74e73999298c72322a84c P d714efdbf43f453b814f75bdb8c5402b: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:46.041301 21435 tablet_bootstrap.cc:492] T f72a813222b74e73999298c72322a84c P d714efdbf43f453b814f75bdb8c5402b: No bootstrap required, opened a new log
I20260812 06:19:46.041433 21435 ts_tablet_manager.cc:1403] T f72a813222b74e73999298c72322a84c P d714efdbf43f453b814f75bdb8c5402b: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:19:46.042021 21435 raft_consensus.cc:359] T f72a813222b74e73999298c72322a84c P d714efdbf43f453b814f75bdb8c5402b [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d714efdbf43f453b814f75bdb8c5402b" member_type: VOTER last_known_addr { host: "127.20.173.129" port: 34521 } }
I20260812 06:19:46.042174 21435 raft_consensus.cc:385] T f72a813222b74e73999298c72322a84c P d714efdbf43f453b814f75bdb8c5402b [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:46.042214 21435 raft_consensus.cc:740] T f72a813222b74e73999298c72322a84c P d714efdbf43f453b814f75bdb8c5402b [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: d714efdbf43f453b814f75bdb8c5402b, State: Initialized, Role: FOLLOWER
I20260812 06:19:46.042356 21435 consensus_queue.cc:260] T f72a813222b74e73999298c72322a84c P d714efdbf43f453b814f75bdb8c5402b [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: "d714efdbf43f453b814f75bdb8c5402b" member_type: VOTER last_known_addr { host: "127.20.173.129" port: 34521 } }
I20260812 06:19:46.042456 21435 raft_consensus.cc:399] T f72a813222b74e73999298c72322a84c P d714efdbf43f453b814f75bdb8c5402b [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:46.042493 21435 raft_consensus.cc:493] T f72a813222b74e73999298c72322a84c P d714efdbf43f453b814f75bdb8c5402b [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:46.042542 21435 raft_consensus.cc:3060] T f72a813222b74e73999298c72322a84c P d714efdbf43f453b814f75bdb8c5402b [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:46.043519 21435 raft_consensus.cc:515] T f72a813222b74e73999298c72322a84c P d714efdbf43f453b814f75bdb8c5402b [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d714efdbf43f453b814f75bdb8c5402b" member_type: VOTER last_known_addr { host: "127.20.173.129" port: 34521 } }
I20260812 06:19:46.043675 21435 leader_election.cc:304] T f72a813222b74e73999298c72322a84c P d714efdbf43f453b814f75bdb8c5402b [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: d714efdbf43f453b814f75bdb8c5402b; no voters: 
I20260812 06:19:46.043931 21435 leader_election.cc:290] T f72a813222b74e73999298c72322a84c P d714efdbf43f453b814f75bdb8c5402b [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:46.044057 21438 raft_consensus.cc:2804] T f72a813222b74e73999298c72322a84c P d714efdbf43f453b814f75bdb8c5402b [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:46.044296 21435 ts_tablet_manager.cc:1434] T f72a813222b74e73999298c72322a84c P d714efdbf43f453b814f75bdb8c5402b: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:19:46.044313 21438 raft_consensus.cc:697] T f72a813222b74e73999298c72322a84c P d714efdbf43f453b814f75bdb8c5402b [term 1 LEADER]: Becoming Leader. State: Replica: d714efdbf43f453b814f75bdb8c5402b, State: Running, Role: LEADER
I20260812 06:19:46.044502 21438 consensus_queue.cc:237] T f72a813222b74e73999298c72322a84c P d714efdbf43f453b814f75bdb8c5402b [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: "d714efdbf43f453b814f75bdb8c5402b" member_type: VOTER last_known_addr { host: "127.20.173.129" port: 34521 } }
I20260812 06:19:46.044826 21422 heartbeater.cc:499] Master 127.20.173.190:36395 was elected leader, sending a full tablet report...
I20260812 06:19:46.047391 21213 catalog_manager.cc:5719] T f72a813222b74e73999298c72322a84c P d714efdbf43f453b814f75bdb8c5402b reported cstate change: term changed from 0 to 1, leader changed from <none> to d714efdbf43f453b814f75bdb8c5402b (127.20.173.129). New cstate: current_term: 1 leader_uuid: "d714efdbf43f453b814f75bdb8c5402b" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d714efdbf43f453b814f75bdb8c5402b" member_type: VOTER last_known_addr { host: "127.20.173.129" port: 34521 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:46.111356 21174 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.054s	user 0.022s	sys 0.002s
I20260812 06:19:46.244338 21423 maintenance_manager.cc:419] P d714efdbf43f453b814f75bdb8c5402b: Scheduling FlushMRSOp(f72a813222b74e73999298c72322a84c): perf score=19.054940
I20260812 06:19:46.380198 21335 maintenance_manager.cc:643] P d714efdbf43f453b814f75bdb8c5402b: FlushMRSOp(f72a813222b74e73999298c72322a84c) complete. Timing: real 0.135s	user 0.116s	sys 0.016s Metrics: {"bytes_written":8615323,"cfile_init":1,"compiler_manager_pool.queue_time_us":226,"delete_count":0,"dirs.queue_time_us":65,"dirs.run_cpu_time_us":207,"dirs.run_wall_time_us":838,"drs_written":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4,"lbm_write_time_us":31456,"lbm_writes_lt_1ms":667,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"thread_start_us":131,"threads_started":1,"update_count":1050}
I20260812 06:19:46.381507 21423 maintenance_manager.cc:419] P d714efdbf43f453b814f75bdb8c5402b: Scheduling UndoDeltaBlockGCOp(f72a813222b74e73999298c72322a84c): 16411393 bytes on disk
I20260812 06:19:46.382210 21335 maintenance_manager.cc:643] P d714efdbf43f453b814f75bdb8c5402b: UndoDeltaBlockGCOp(f72a813222b74e73999298c72322a84c) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":78,"lbm_reads_lt_1ms":4}
I20260812 06:19:46.382690 21423 maintenance_manager.cc:419] P d714efdbf43f453b814f75bdb8c5402b: Scheduling FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c): perf score=2.188937
I20260812 06:19:46.397039 21335 maintenance_manager.cc:643] P d714efdbf43f453b814f75bdb8c5402b: FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c) complete. Timing: real 0.014s	user 0.004s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5053,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:46.397631 21423 maintenance_manager.cc:419] P d714efdbf43f453b814f75bdb8c5402b: Scheduling LogGCOp(f72a813222b74e73999298c72322a84c): free 20743880 bytes of WAL
I20260812 06:19:46.398011 21335 log_reader.cc:385] T f72a813222b74e73999298c72322a84c: removed 2 log segments from log reader
I20260812 06:19:46.398099 21335 log.cc:1079] T f72a813222b74e73999298c72322a84c P d714efdbf43f453b814f75bdb8c5402b: Deleting log segment in path: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585830708-21174-0/minicluster-data/ts-0-root/wals/f72a813222b74e73999298c72322a84c/wal-000000001 (ops 1-6)
I20260812 06:19:46.398169 21335 log.cc:1079] T f72a813222b74e73999298c72322a84c P d714efdbf43f453b814f75bdb8c5402b: Deleting log segment in path: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585830708-21174-0/minicluster-data/ts-0-root/wals/f72a813222b74e73999298c72322a84c/wal-000000002 (ops 7-11)
I20260812 06:19:46.403407 21335 maintenance_manager.cc:643] P d714efdbf43f453b814f75bdb8c5402b: LogGCOp(f72a813222b74e73999298c72322a84c) complete. Timing: real 0.006s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:19:46.403923 21423 maintenance_manager.cc:419] P d714efdbf43f453b814f75bdb8c5402b: Scheduling MajorDeltaCompactionOp(f72a813222b74e73999298c72322a84c): perf score=1.000000
I20260812 06:19:46.514789 21335 maintenance_manager.cc:643] P d714efdbf43f453b814f75bdb8c5402b: MajorDeltaCompactionOp(f72a813222b74e73999298c72322a84c) complete. Timing: real 0.111s	user 0.077s	sys 0.031s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16569856,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":593,"lbm_read_time_us":8250,"lbm_reads_lt_1ms":360,"lbm_write_time_us":18598,"lbm_writes_lt_1ms":343,"mutex_wait_us":31,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":309,"threads_started":5,"update_count":1500}
I20260812 06:19:46.515333 21423 maintenance_manager.cc:419] P d714efdbf43f453b814f75bdb8c5402b: Scheduling FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c): perf score=7.149875
I20260812 06:19:46.538877 21335 maintenance_manager.cc:643] P d714efdbf43f453b814f75bdb8c5402b: FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c) complete. Timing: real 0.023s	user 0.004s	sys 0.018s Metrics: {"bytes_written":8615323,"delete_count":0,"lbm_write_time_us":9745,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":212,"reinsert_count":0,"update_count":1050}
I20260812 06:19:46.539395 21423 maintenance_manager.cc:419] P d714efdbf43f453b814f75bdb8c5402b: Scheduling FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c): perf score=2.188937
I20260812 06:19:46.556007 21335 maintenance_manager.cc:643] P d714efdbf43f453b814f75bdb8c5402b: FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c) complete. Timing: real 0.016s	user 0.004s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5327,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:46.556604 21423 maintenance_manager.cc:419] P d714efdbf43f453b814f75bdb8c5402b: Scheduling MajorDeltaCompactionOp(f72a813222b74e73999298c72322a84c): perf score=1.000000
I20260812 06:19:46.652603 21335 maintenance_manager.cc:643] P d714efdbf43f453b814f75bdb8c5402b: MajorDeltaCompactionOp(f72a813222b74e73999298c72322a84c) complete. Timing: real 0.096s	user 0.079s	sys 0.016s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16569856,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":980,"lbm_read_time_us":6024,"lbm_reads_lt_1ms":364,"lbm_write_time_us":17961,"lbm_writes_lt_1ms":343,"mutex_wait_us":320,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":36480,"update_count":1500}
I20260812 06:19:46.653182 21423 maintenance_manager.cc:419] P d714efdbf43f453b814f75bdb8c5402b: Scheduling FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c): perf score=10.126437
I20260812 06:19:46.696210 21335 maintenance_manager.cc:643] P d714efdbf43f453b814f75bdb8c5402b: FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c) complete. Timing: real 0.043s	user 0.016s	sys 0.016s Metrics: {"bytes_written":12307494,"delete_count":0,"lbm_write_time_us":14988,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:46.696712 21423 maintenance_manager.cc:419] P d714efdbf43f453b814f75bdb8c5402b: Scheduling FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c): perf score=2.188937
I20260812 06:19:46.707876 21335 maintenance_manager.cc:643] P d714efdbf43f453b814f75bdb8c5402b: FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c) complete. Timing: real 0.011s	user 0.005s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3675,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:46.708513 21423 maintenance_manager.cc:419] P d714efdbf43f453b814f75bdb8c5402b: Scheduling MajorDeltaCompactionOp(f72a813222b74e73999298c72322a84c): perf score=1.000000
I20260812 06:19:46.833472 21335 maintenance_manager.cc:643] P d714efdbf43f453b814f75bdb8c5402b: MajorDeltaCompactionOp(f72a813222b74e73999298c72322a84c) complete. Timing: real 0.125s	user 0.087s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672281,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1217,"lbm_read_time_us":8273,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23554,"lbm_writes_lt_1ms":443,"mutex_wait_us":298,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:19:46.834160 21423 maintenance_manager.cc:419] P d714efdbf43f453b814f75bdb8c5402b: Scheduling FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c): perf score=10.126437
I20260812 06:19:46.873117 21335 maintenance_manager.cc:643] P d714efdbf43f453b814f75bdb8c5402b: FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c) complete. Timing: real 0.039s	user 0.012s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13239,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:46.873610 21423 maintenance_manager.cc:419] P d714efdbf43f453b814f75bdb8c5402b: Scheduling FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c): perf score=2.188937
I20260812 06:19:46.884008 21335 maintenance_manager.cc:643] P d714efdbf43f453b814f75bdb8c5402b: FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c) complete. Timing: real 0.010s	user 0.004s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3800,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:46.884598 21423 maintenance_manager.cc:419] P d714efdbf43f453b814f75bdb8c5402b: Scheduling MajorDeltaCompactionOp(f72a813222b74e73999298c72322a84c): perf score=1.000000
I20260812 06:19:47.007617 21335 maintenance_manager.cc:643] P d714efdbf43f453b814f75bdb8c5402b: MajorDeltaCompactionOp(f72a813222b74e73999298c72322a84c) complete. Timing: real 0.123s	user 0.102s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":2500,"lbm_read_time_us":8495,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24509,"lbm_writes_lt_1ms":443,"mutex_wait_us":627,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:19:47.008179 21423 maintenance_manager.cc:419] P d714efdbf43f453b814f75bdb8c5402b: Scheduling FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c): perf score=10.126437
I20260812 06:19:47.051332 21335 maintenance_manager.cc:643] P d714efdbf43f453b814f75bdb8c5402b: FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c) complete. Timing: real 0.043s	user 0.021s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14541,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:47.051940 21423 maintenance_manager.cc:419] P d714efdbf43f453b814f75bdb8c5402b: Scheduling FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c): perf score=2.188937
I20260812 06:19:47.062916 21335 maintenance_manager.cc:643] P d714efdbf43f453b814f75bdb8c5402b: FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3908,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:47.063491 21423 maintenance_manager.cc:419] P d714efdbf43f453b814f75bdb8c5402b: Scheduling MajorDeltaCompactionOp(f72a813222b74e73999298c72322a84c): perf score=1.000000
I20260812 06:19:47.179970 21335 maintenance_manager.cc:643] P d714efdbf43f453b814f75bdb8c5402b: MajorDeltaCompactionOp(f72a813222b74e73999298c72322a84c) complete. Timing: real 0.116s	user 0.081s	sys 0.035s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1076,"lbm_read_time_us":10130,"lbm_reads_lt_1ms":472,"lbm_write_time_us":20229,"lbm_writes_lt_1ms":443,"mutex_wait_us":282,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":2000}
I20260812 06:19:47.180480 21423 maintenance_manager.cc:419] P d714efdbf43f453b814f75bdb8c5402b: Scheduling FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c): perf score=10.126437
I20260812 06:19:47.221462 21335 maintenance_manager.cc:643] P d714efdbf43f453b814f75bdb8c5402b: FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c) complete. Timing: real 0.041s	user 0.017s	sys 0.024s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15083,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:47.222025 21423 maintenance_manager.cc:419] P d714efdbf43f453b814f75bdb8c5402b: Scheduling MajorDeltaCompactionOp(f72a813222b74e73999298c72322a84c): perf score=1.000000
I20260812 06:19:47.340762 21335 maintenance_manager.cc:643] P d714efdbf43f453b814f75bdb8c5402b: MajorDeltaCompactionOp(f72a813222b74e73999298c72322a84c) complete. Timing: real 0.119s	user 0.097s	sys 0.021s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16569746,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":2012,"lbm_read_time_us":7794,"lbm_reads_lt_1ms":363,"lbm_write_time_us":18431,"lbm_writes_lt_1ms":343,"mutex_wait_us":529,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":1920,"update_count":1500}
I20260812 06:19:47.341320 21423 maintenance_manager.cc:419] P d714efdbf43f453b814f75bdb8c5402b: Scheduling FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c): perf score=10.126437
I20260812 06:19:47.387487 21335 maintenance_manager.cc:643] P d714efdbf43f453b814f75bdb8c5402b: FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c) complete. Timing: real 0.046s	user 0.022s	sys 0.010s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14161,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:47.388031 21423 maintenance_manager.cc:419] P d714efdbf43f453b814f75bdb8c5402b: Scheduling FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c): perf score=2.188937
I20260812 06:19:47.403561 21335 maintenance_manager.cc:643] P d714efdbf43f453b814f75bdb8c5402b: FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c) complete. Timing: real 0.015s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5353,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:47.404184 21423 maintenance_manager.cc:419] P d714efdbf43f453b814f75bdb8c5402b: Scheduling MajorDeltaCompactionOp(f72a813222b74e73999298c72322a84c): perf score=1.000000
I20260812 06:19:47.546650 21335 maintenance_manager.cc:643] P d714efdbf43f453b814f75bdb8c5402b: MajorDeltaCompactionOp(f72a813222b74e73999298c72322a84c) complete. Timing: real 0.142s	user 0.108s	sys 0.031s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":181,"lbm_read_time_us":9798,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27551,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:19:47.547149 21423 maintenance_manager.cc:419] P d714efdbf43f453b814f75bdb8c5402b: Scheduling FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c): perf score=10.126437
I20260812 06:19:47.581398 21335 maintenance_manager.cc:643] P d714efdbf43f453b814f75bdb8c5402b: FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c) complete. Timing: real 0.034s	user 0.030s	sys 0.003s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":14564,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:47.581918 21423 maintenance_manager.cc:419] P d714efdbf43f453b814f75bdb8c5402b: Scheduling FlushMRSOp(f72a813222b74e73999298c72322a84c): perf score=1.000000
I20260812 06:19:47.620983 21335 maintenance_manager.cc:643] P d714efdbf43f453b814f75bdb8c5402b: FlushMRSOp(f72a813222b74e73999298c72322a84c) complete. Timing: real 0.039s	user 0.023s	sys 0.003s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":80,"dirs.run_cpu_time_us":301,"dirs.run_wall_time_us":1470,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1967,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:47.621987 21423 maintenance_manager.cc:419] P d714efdbf43f453b814f75bdb8c5402b: Scheduling UndoDeltaBlockGCOp(f72a813222b74e73999298c72322a84c): 462 bytes on disk
I20260812 06:19:47.622538 21335 maintenance_manager.cc:643] P d714efdbf43f453b814f75bdb8c5402b: UndoDeltaBlockGCOp(f72a813222b74e73999298c72322a84c) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":51,"lbm_reads_lt_1ms":4}
I20260812 06:19:47.623121 21423 maintenance_manager.cc:419] P d714efdbf43f453b814f75bdb8c5402b: Scheduling FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c): perf score=3.181125
I20260812 06:19:47.635022 21335 maintenance_manager.cc:643] P d714efdbf43f453b814f75bdb8c5402b: FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4071,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:47.635492 21423 maintenance_manager.cc:419] P d714efdbf43f453b814f75bdb8c5402b: Scheduling LogGCOp(f72a813222b74e73999298c72322a84c): free 112239306 bytes of WAL
I20260812 06:19:47.635699 21335 log_reader.cc:385] T f72a813222b74e73999298c72322a84c: removed 11 log segments from log reader
I20260812 06:19:47.635747 21335 log.cc:1079] T f72a813222b74e73999298c72322a84c P d714efdbf43f453b814f75bdb8c5402b: Deleting log segment in path: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585830708-21174-0/minicluster-data/ts-0-root/wals/f72a813222b74e73999298c72322a84c/wal-000000003 (ops 12-16)
I20260812 06:19:47.635775 21335 log.cc:1079] T f72a813222b74e73999298c72322a84c P d714efdbf43f453b814f75bdb8c5402b: Deleting log segment in path: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585830708-21174-0/minicluster-data/ts-0-root/wals/f72a813222b74e73999298c72322a84c/wal-000000004 (ops 17-21)
I20260812 06:19:47.635807 21335 log.cc:1079] T f72a813222b74e73999298c72322a84c P d714efdbf43f453b814f75bdb8c5402b: Deleting log segment in path: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585830708-21174-0/minicluster-data/ts-0-root/wals/f72a813222b74e73999298c72322a84c/wal-000000005 (ops 22-26)
I20260812 06:19:47.635839 21335 log.cc:1079] T f72a813222b74e73999298c72322a84c P d714efdbf43f453b814f75bdb8c5402b: Deleting log segment in path: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585830708-21174-0/minicluster-data/ts-0-root/wals/f72a813222b74e73999298c72322a84c/wal-000000006 (ops 27-31)
I20260812 06:19:47.635871 21335 log.cc:1079] T f72a813222b74e73999298c72322a84c P d714efdbf43f453b814f75bdb8c5402b: Deleting log segment in path: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585830708-21174-0/minicluster-data/ts-0-root/wals/f72a813222b74e73999298c72322a84c/wal-000000007 (ops 32-36)
I20260812 06:19:47.635902 21335 log.cc:1079] T f72a813222b74e73999298c72322a84c P d714efdbf43f453b814f75bdb8c5402b: Deleting log segment in path: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585830708-21174-0/minicluster-data/ts-0-root/wals/f72a813222b74e73999298c72322a84c/wal-000000008 (ops 37-41)
I20260812 06:19:47.635934 21335 log.cc:1079] T f72a813222b74e73999298c72322a84c P d714efdbf43f453b814f75bdb8c5402b: Deleting log segment in path: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585830708-21174-0/minicluster-data/ts-0-root/wals/f72a813222b74e73999298c72322a84c/wal-000000009 (ops 42-46)
I20260812 06:19:47.635967 21335 log.cc:1079] T f72a813222b74e73999298c72322a84c P d714efdbf43f453b814f75bdb8c5402b: Deleting log segment in path: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585830708-21174-0/minicluster-data/ts-0-root/wals/f72a813222b74e73999298c72322a84c/wal-000000010 (ops 47-51)
I20260812 06:19:47.635998 21335 log.cc:1079] T f72a813222b74e73999298c72322a84c P d714efdbf43f453b814f75bdb8c5402b: Deleting log segment in path: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585830708-21174-0/minicluster-data/ts-0-root/wals/f72a813222b74e73999298c72322a84c/wal-000000011 (ops 52-56)
I20260812 06:19:47.636035 21335 log.cc:1079] T f72a813222b74e73999298c72322a84c P d714efdbf43f453b814f75bdb8c5402b: Deleting log segment in path: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585830708-21174-0/minicluster-data/ts-0-root/wals/f72a813222b74e73999298c72322a84c/wal-000000012 (ops 57-60)
I20260812 06:19:47.636067 21335 log.cc:1079] T f72a813222b74e73999298c72322a84c P d714efdbf43f453b814f75bdb8c5402b: Deleting log segment in path: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585830708-21174-0/minicluster-data/ts-0-root/wals/f72a813222b74e73999298c72322a84c/wal-000000013 (ops 61-65)
I20260812 06:19:47.656926 21335 maintenance_manager.cc:643] P d714efdbf43f453b814f75bdb8c5402b: LogGCOp(f72a813222b74e73999298c72322a84c) complete. Timing: real 0.021s	user 0.000s	sys 0.018s Metrics: {}
I20260812 06:19:47.657352 21423 maintenance_manager.cc:419] P d714efdbf43f453b814f75bdb8c5402b: Scheduling FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c): perf score=2.188937
I20260812 06:19:47.674512 21335 maintenance_manager.cc:643] P d714efdbf43f453b814f75bdb8c5402b: FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c) complete. Timing: real 0.017s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3721,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:47.675050 21423 maintenance_manager.cc:419] P d714efdbf43f453b814f75bdb8c5402b: Scheduling FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c): perf score=2.188937
I20260812 06:19:47.684988 21335 maintenance_manager.cc:643] P d714efdbf43f453b814f75bdb8c5402b: FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c) complete. Timing: real 0.010s	user 0.000s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3483,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:47.685647 21423 maintenance_manager.cc:419] P d714efdbf43f453b814f75bdb8c5402b: Scheduling MajorDeltaCompactionOp(f72a813222b74e73999298c72322a84c): perf score=1.000000
I20260812 06:19:47.858039 21335 maintenance_manager.cc:643] P d714efdbf43f453b814f75bdb8c5402b: MajorDeltaCompactionOp(f72a813222b74e73999298c72322a84c) complete. Timing: real 0.172s	user 0.119s	sys 0.046s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877329,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":448,"lbm_read_time_us":12629,"lbm_reads_lt_1ms":674,"lbm_write_time_us":31746,"lbm_writes_lt_1ms":643,"mutex_wait_us":49,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2176,"thread_start_us":91,"threads_started":1,"update_count":3000}
I20260812 06:19:47.858505 21423 maintenance_manager.cc:419] P d714efdbf43f453b814f75bdb8c5402b: Scheduling FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c): perf score=14.095187
I20260812 06:19:47.905309 21335 maintenance_manager.cc:643] P d714efdbf43f453b814f75bdb8c5402b: FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c) complete. Timing: real 0.047s	user 0.024s	sys 0.016s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":17567,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:47.905828 21423 maintenance_manager.cc:419] P d714efdbf43f453b814f75bdb8c5402b: Scheduling FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c): perf score=2.188937
I20260812 06:19:47.916136 21335 maintenance_manager.cc:643] P d714efdbf43f453b814f75bdb8c5402b: FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3629,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:47.916721 21423 maintenance_manager.cc:419] P d714efdbf43f453b814f75bdb8c5402b: Scheduling MajorDeltaCompactionOp(f72a813222b74e73999298c72322a84c): perf score=1.000000
I20260812 06:19:48.075328 21335 maintenance_manager.cc:643] P d714efdbf43f453b814f75bdb8c5402b: MajorDeltaCompactionOp(f72a813222b74e73999298c72322a84c) complete. Timing: real 0.158s	user 0.112s	sys 0.036s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774686,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1195,"lbm_read_time_us":9708,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27935,"lbm_writes_lt_1ms":543,"mutex_wait_us":54,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":24832,"update_count":2500}
I20260812 06:19:48.076145 21423 maintenance_manager.cc:419] P d714efdbf43f453b814f75bdb8c5402b: Scheduling FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c): perf score=14.095187
I20260812 06:19:48.137064 21335 maintenance_manager.cc:643] P d714efdbf43f453b814f75bdb8c5402b: FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c) complete. Timing: real 0.061s	user 0.028s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21832,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:19:48.137584 21423 maintenance_manager.cc:419] P d714efdbf43f453b814f75bdb8c5402b: Scheduling FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c): perf score=2.188937
I20260812 06:19:48.148440 21335 maintenance_manager.cc:643] P d714efdbf43f453b814f75bdb8c5402b: FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c) complete. Timing: real 0.011s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3736,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:48.149118 21423 maintenance_manager.cc:419] P d714efdbf43f453b814f75bdb8c5402b: Scheduling MajorDeltaCompactionOp(f72a813222b74e73999298c72322a84c): perf score=1.000000
I20260812 06:19:48.318250 21335 maintenance_manager.cc:643] P d714efdbf43f453b814f75bdb8c5402b: MajorDeltaCompactionOp(f72a813222b74e73999298c72322a84c) complete. Timing: real 0.169s	user 0.114s	sys 0.047s 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":537,"lbm_read_time_us":10902,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26461,"lbm_writes_lt_1ms":543,"mutex_wait_us":307,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":39040,"update_count":2500}
I20260812 06:19:48.318847 21423 maintenance_manager.cc:419] P d714efdbf43f453b814f75bdb8c5402b: Scheduling FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c): perf score=14.095187
I20260812 06:19:48.368564 21335 maintenance_manager.cc:643] P d714efdbf43f453b814f75bdb8c5402b: FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c) complete. Timing: real 0.050s	user 0.026s	sys 0.014s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18254,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:48.369118 21423 maintenance_manager.cc:419] P d714efdbf43f453b814f75bdb8c5402b: Scheduling FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c): perf score=2.188937
I20260812 06:19:48.381063 21335 maintenance_manager.cc:643] P d714efdbf43f453b814f75bdb8c5402b: FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4268,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:48.381609 21423 maintenance_manager.cc:419] P d714efdbf43f453b814f75bdb8c5402b: Scheduling MajorDeltaCompactionOp(f72a813222b74e73999298c72322a84c): perf score=1.000000
I20260812 06:19:48.549052 21335 maintenance_manager.cc:643] P d714efdbf43f453b814f75bdb8c5402b: MajorDeltaCompactionOp(f72a813222b74e73999298c72322a84c) complete. Timing: real 0.167s	user 0.118s	sys 0.040s 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":263,"lbm_read_time_us":12121,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26574,"lbm_writes_lt_1ms":543,"mutex_wait_us":46,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2560,"update_count":2500}
I20260812 06:19:48.549687 21423 maintenance_manager.cc:419] P d714efdbf43f453b814f75bdb8c5402b: Scheduling FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c): perf score=14.095187
I20260812 06:19:48.609354 21335 maintenance_manager.cc:643] P d714efdbf43f453b814f75bdb8c5402b: FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c) complete. Timing: real 0.059s	user 0.031s	sys 0.022s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":19672,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:48.609989 21423 maintenance_manager.cc:419] P d714efdbf43f453b814f75bdb8c5402b: Scheduling FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c): perf score=2.188937
I20260812 06:19:48.624346 21335 maintenance_manager.cc:643] P d714efdbf43f453b814f75bdb8c5402b: FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c) complete. Timing: real 0.014s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5630,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:48.624835 21423 maintenance_manager.cc:419] P d714efdbf43f453b814f75bdb8c5402b: Scheduling MajorDeltaCompactionOp(f72a813222b74e73999298c72322a84c): perf score=1.000000
I20260812 06:19:48.798436 21335 maintenance_manager.cc:643] P d714efdbf43f453b814f75bdb8c5402b: MajorDeltaCompactionOp(f72a813222b74e73999298c72322a84c) complete. Timing: real 0.173s	user 0.096s	sys 0.071s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774692,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":606,"lbm_read_time_us":12929,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28219,"lbm_writes_lt_1ms":543,"mutex_wait_us":296,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":29440,"update_count":2500}
I20260812 06:19:48.798926 21423 maintenance_manager.cc:419] P d714efdbf43f453b814f75bdb8c5402b: Scheduling FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c): perf score=11.118625
I20260812 06:19:48.840937 21335 maintenance_manager.cc:643] P d714efdbf43f453b814f75bdb8c5402b: FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c) complete. Timing: real 0.042s	user 0.017s	sys 0.024s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":14628,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:48.841670 21423 maintenance_manager.cc:419] P d714efdbf43f453b814f75bdb8c5402b: Scheduling FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c): perf score=2.188937
I20260812 06:19:48.875818 21335 maintenance_manager.cc:643] P d714efdbf43f453b814f75bdb8c5402b: FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c) complete. Timing: real 0.034s	user 0.000s	sys 0.021s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5833,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:48.876441 21423 maintenance_manager.cc:419] P d714efdbf43f453b814f75bdb8c5402b: Scheduling FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c): perf score=2.188937
I20260812 06:19:48.891031 21335 maintenance_manager.cc:643] P d714efdbf43f453b814f75bdb8c5402b: FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c) complete. Timing: real 0.014s	user 0.005s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5318,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:48.891661 21423 maintenance_manager.cc:419] P d714efdbf43f453b814f75bdb8c5402b: Scheduling MajorDeltaCompactionOp(f72a813222b74e73999298c72322a84c): perf score=1.000000
I20260812 06:19:49.057502 21335 maintenance_manager.cc:643] P d714efdbf43f453b814f75bdb8c5402b: MajorDeltaCompactionOp(f72a813222b74e73999298c72322a84c) complete. Timing: real 0.166s	user 0.138s	sys 0.027s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774799,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":146,"lbm_read_time_us":12681,"lbm_reads_lt_1ms":573,"lbm_write_time_us":28416,"lbm_writes_lt_1ms":543,"mutex_wait_us":19,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":46848,"update_count":2500}
I20260812 06:19:49.058256 21423 maintenance_manager.cc:419] P d714efdbf43f453b814f75bdb8c5402b: Scheduling FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c): perf score=10.126437
I20260812 06:19:49.091784 21335 maintenance_manager.cc:643] P d714efdbf43f453b814f75bdb8c5402b: FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c) complete. Timing: real 0.033s	user 0.023s	sys 0.004s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":12497,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:49.092415 21423 maintenance_manager.cc:419] P d714efdbf43f453b814f75bdb8c5402b: Scheduling FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c): perf score=2.188937
I20260812 06:19:49.108421 21335 maintenance_manager.cc:643] P d714efdbf43f453b814f75bdb8c5402b: FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c) complete. Timing: real 0.016s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5899,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:49.109236 21423 maintenance_manager.cc:419] P d714efdbf43f453b814f75bdb8c5402b: Scheduling FlushMRSOp(f72a813222b74e73999298c72322a84c): perf score=1.000000
I20260812 06:19:49.143280 21335 maintenance_manager.cc:643] P d714efdbf43f453b814f75bdb8c5402b: FlushMRSOp(f72a813222b74e73999298c72322a84c) complete. Timing: real 0.034s	user 0.032s	sys 0.000s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":46,"dirs.run_cpu_time_us":214,"dirs.run_wall_time_us":1312,"drs_written":1,"lbm_read_time_us":46,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2017,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:49.144011 21423 maintenance_manager.cc:419] P d714efdbf43f453b814f75bdb8c5402b: Scheduling LogGCOp(f72a813222b74e73999298c72322a84c): free 129320505 bytes of WAL
I20260812 06:19:49.144237 21335 log_reader.cc:385] T f72a813222b74e73999298c72322a84c: removed 13 log segments from log reader
I20260812 06:19:49.144286 21335 log.cc:1079] T f72a813222b74e73999298c72322a84c P d714efdbf43f453b814f75bdb8c5402b: Deleting log segment in path: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585830708-21174-0/minicluster-data/ts-0-root/wals/f72a813222b74e73999298c72322a84c/wal-000000014 (ops 66-70)
I20260812 06:19:49.144313 21335 log.cc:1079] T f72a813222b74e73999298c72322a84c P d714efdbf43f453b814f75bdb8c5402b: Deleting log segment in path: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585830708-21174-0/minicluster-data/ts-0-root/wals/f72a813222b74e73999298c72322a84c/wal-000000015 (ops 71-74)
I20260812 06:19:49.144345 21335 log.cc:1079] T f72a813222b74e73999298c72322a84c P d714efdbf43f453b814f75bdb8c5402b: Deleting log segment in path: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585830708-21174-0/minicluster-data/ts-0-root/wals/f72a813222b74e73999298c72322a84c/wal-000000016 (ops 75-79)
I20260812 06:19:49.144376 21335 log.cc:1079] T f72a813222b74e73999298c72322a84c P d714efdbf43f453b814f75bdb8c5402b: Deleting log segment in path: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585830708-21174-0/minicluster-data/ts-0-root/wals/f72a813222b74e73999298c72322a84c/wal-000000017 (ops 80-84)
I20260812 06:19:49.144409 21335 log.cc:1079] T f72a813222b74e73999298c72322a84c P d714efdbf43f453b814f75bdb8c5402b: Deleting log segment in path: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585830708-21174-0/minicluster-data/ts-0-root/wals/f72a813222b74e73999298c72322a84c/wal-000000018 (ops 85-89)
I20260812 06:19:49.144459 21335 log.cc:1079] T f72a813222b74e73999298c72322a84c P d714efdbf43f453b814f75bdb8c5402b: Deleting log segment in path: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585830708-21174-0/minicluster-data/ts-0-root/wals/f72a813222b74e73999298c72322a84c/wal-000000019 (ops 90-94)
I20260812 06:19:49.144484 21335 log.cc:1079] T f72a813222b74e73999298c72322a84c P d714efdbf43f453b814f75bdb8c5402b: Deleting log segment in path: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585830708-21174-0/minicluster-data/ts-0-root/wals/f72a813222b74e73999298c72322a84c/wal-000000020 (ops 95-98)
I20260812 06:19:49.144511 21335 log.cc:1079] T f72a813222b74e73999298c72322a84c P d714efdbf43f453b814f75bdb8c5402b: Deleting log segment in path: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585830708-21174-0/minicluster-data/ts-0-root/wals/f72a813222b74e73999298c72322a84c/wal-000000021 (ops 99-103)
I20260812 06:19:49.144544 21335 log.cc:1079] T f72a813222b74e73999298c72322a84c P d714efdbf43f453b814f75bdb8c5402b: Deleting log segment in path: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585830708-21174-0/minicluster-data/ts-0-root/wals/f72a813222b74e73999298c72322a84c/wal-000000022 (ops 104-108)
I20260812 06:19:49.144568 21335 log.cc:1079] T f72a813222b74e73999298c72322a84c P d714efdbf43f453b814f75bdb8c5402b: Deleting log segment in path: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585830708-21174-0/minicluster-data/ts-0-root/wals/f72a813222b74e73999298c72322a84c/wal-000000023 (ops 109-113)
I20260812 06:19:49.144600 21335 log.cc:1079] T f72a813222b74e73999298c72322a84c P d714efdbf43f453b814f75bdb8c5402b: Deleting log segment in path: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585830708-21174-0/minicluster-data/ts-0-root/wals/f72a813222b74e73999298c72322a84c/wal-000000024 (ops 114-118)
I20260812 06:19:49.144632 21335 log.cc:1079] T f72a813222b74e73999298c72322a84c P d714efdbf43f453b814f75bdb8c5402b: Deleting log segment in path: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585830708-21174-0/minicluster-data/ts-0-root/wals/f72a813222b74e73999298c72322a84c/wal-000000025 (ops 119-123)
I20260812 06:19:49.144665 21335 log.cc:1079] T f72a813222b74e73999298c72322a84c P d714efdbf43f453b814f75bdb8c5402b: Deleting log segment in path: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585830708-21174-0/minicluster-data/ts-0-root/wals/f72a813222b74e73999298c72322a84c/wal-000000026 (ops 124-128)
I20260812 06:19:49.167029 21335 maintenance_manager.cc:643] P d714efdbf43f453b814f75bdb8c5402b: LogGCOp(f72a813222b74e73999298c72322a84c) complete. Timing: real 0.023s	user 0.000s	sys 0.021s Metrics: {}
I20260812 06:19:49.167747 21423 maintenance_manager.cc:419] P d714efdbf43f453b814f75bdb8c5402b: Scheduling FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c): perf score=3.181125
I20260812 06:19:49.189764 21335 maintenance_manager.cc:643] P d714efdbf43f453b814f75bdb8c5402b: FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c) complete. Timing: real 0.022s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4024,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:49.190341 21423 maintenance_manager.cc:419] P d714efdbf43f453b814f75bdb8c5402b: Scheduling UndoDeltaBlockGCOp(f72a813222b74e73999298c72322a84c): 483 bytes on disk
I20260812 06:19:49.190873 21335 maintenance_manager.cc:643] P d714efdbf43f453b814f75bdb8c5402b: UndoDeltaBlockGCOp(f72a813222b74e73999298c72322a84c) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":60,"lbm_reads_lt_1ms":4}
I20260812 06:19:49.191494 21423 maintenance_manager.cc:419] P d714efdbf43f453b814f75bdb8c5402b: Scheduling FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c): perf score=2.188937
I20260812 06:19:49.201423 21335 maintenance_manager.cc:643] P d714efdbf43f453b814f75bdb8c5402b: FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3566,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:49.202033 21423 maintenance_manager.cc:419] P d714efdbf43f453b814f75bdb8c5402b: Scheduling MajorDeltaCompactionOp(f72a813222b74e73999298c72322a84c): perf score=1.000000
I20260812 06:19:49.382153 21335 maintenance_manager.cc:643] P d714efdbf43f453b814f75bdb8c5402b: MajorDeltaCompactionOp(f72a813222b74e73999298c72322a84c) complete. Timing: real 0.180s	user 0.125s	sys 0.054s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877328,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":438,"lbm_read_time_us":13429,"lbm_reads_lt_1ms":674,"lbm_write_time_us":29319,"lbm_writes_lt_1ms":643,"mutex_wait_us":65,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":29824,"thread_start_us":84,"threads_started":1,"update_count":3000}
I20260812 06:19:49.384363 21423 maintenance_manager.cc:419] P d714efdbf43f453b814f75bdb8c5402b: Scheduling FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c): perf score=14.095187
I20260812 06:19:49.435863 21335 maintenance_manager.cc:643] P d714efdbf43f453b814f75bdb8c5402b: FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c) complete. Timing: real 0.051s	user 0.030s	sys 0.019s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":18395,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:49.436565 21423 maintenance_manager.cc:419] P d714efdbf43f453b814f75bdb8c5402b: Scheduling FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c): perf score=2.188937
I20260812 06:19:49.452458 21335 maintenance_manager.cc:643] P d714efdbf43f453b814f75bdb8c5402b: FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c) complete. Timing: real 0.016s	user 0.006s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5961,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:49.453003 21423 maintenance_manager.cc:419] P d714efdbf43f453b814f75bdb8c5402b: Scheduling MajorDeltaCompactionOp(f72a813222b74e73999298c72322a84c): perf score=1.000000
I20260812 06:19:49.631599 21335 maintenance_manager.cc:643] P d714efdbf43f453b814f75bdb8c5402b: MajorDeltaCompactionOp(f72a813222b74e73999298c72322a84c) complete. Timing: real 0.178s	user 0.105s	sys 0.062s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":151,"lbm_read_time_us":13707,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26813,"lbm_writes_lt_1ms":543,"mutex_wait_us":67,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3200,"update_count":2500}
I20260812 06:19:49.632151 21423 maintenance_manager.cc:419] P d714efdbf43f453b814f75bdb8c5402b: Scheduling FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c): perf score=14.095187
I20260812 06:19:49.686894 21335 maintenance_manager.cc:643] P d714efdbf43f453b814f75bdb8c5402b: FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c) complete. Timing: real 0.055s	user 0.034s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18278,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:49.687505 21423 maintenance_manager.cc:419] P d714efdbf43f453b814f75bdb8c5402b: Scheduling FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c): perf score=2.188937
I20260812 06:19:49.698153 21335 maintenance_manager.cc:643] P d714efdbf43f453b814f75bdb8c5402b: FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3935,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:49.698626 21423 maintenance_manager.cc:419] P d714efdbf43f453b814f75bdb8c5402b: Scheduling MajorDeltaCompactionOp(f72a813222b74e73999298c72322a84c): perf score=1.000000
I20260812 06:19:49.876699 21335 maintenance_manager.cc:643] P d714efdbf43f453b814f75bdb8c5402b: MajorDeltaCompactionOp(f72a813222b74e73999298c72322a84c) complete. Timing: real 0.178s	user 0.116s	sys 0.057s 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":305,"lbm_read_time_us":13058,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27668,"lbm_writes_lt_1ms":543,"mutex_wait_us":49,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:49.877346 21423 maintenance_manager.cc:419] P d714efdbf43f453b814f75bdb8c5402b: Scheduling FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c): perf score=11.118625
I20260812 06:19:49.959791 21335 maintenance_manager.cc:643] P d714efdbf43f453b814f75bdb8c5402b: FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c) complete. Timing: real 0.082s	user 0.021s	sys 0.016s Metrics: {"bytes_written":12717738,"delete_count":0,"lbm_write_time_us":59932,"lbm_writes_1-10_ms":1,"lbm_writes_10-100_ms":1,"lbm_writes_lt_1ms":311,"reinsert_count":0,"update_count":1550}
I20260812 06:19:49.960464 21423 maintenance_manager.cc:419] P d714efdbf43f453b814f75bdb8c5402b: Scheduling FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c): perf score=6.157687
I20260812 06:19:50.004470 21335 maintenance_manager.cc:643] P d714efdbf43f453b814f75bdb8c5402b: FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c) complete. Timing: real 0.044s	user 0.013s	sys 0.015s Metrics: {"bytes_written":7794836,"delete_count":0,"lbm_write_time_us":8826,"lbm_writes_lt_1ms":193,"reinsert_count":0,"update_count":950}
I20260812 06:19:50.005136 21423 maintenance_manager.cc:419] P d714efdbf43f453b814f75bdb8c5402b: Scheduling FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c): perf score=2.188937
I20260812 06:19:50.021112 21335 maintenance_manager.cc:643] P d714efdbf43f453b814f75bdb8c5402b: FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c) complete. Timing: real 0.016s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5877,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:50.021826 21423 maintenance_manager.cc:419] P d714efdbf43f453b814f75bdb8c5402b: Scheduling MajorDeltaCompactionOp(f72a813222b74e73999298c72322a84c): perf score=1.000000
I20260812 06:19:50.225888 21335 maintenance_manager.cc:643] P d714efdbf43f453b814f75bdb8c5402b: MajorDeltaCompactionOp(f72a813222b74e73999298c72322a84c) complete. Timing: real 0.204s	user 0.128s	sys 0.066s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877227,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1660,"lbm_read_time_us":13886,"lbm_reads_lt_1ms":673,"lbm_write_time_us":33720,"lbm_writes_lt_1ms":643,"mutex_wait_us":345,"peak_mem_usage":75542472,"reinsert_count":0,"update_count":3000}
I20260812 06:19:50.226377 21423 maintenance_manager.cc:419] P d714efdbf43f453b814f75bdb8c5402b: Scheduling FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c): perf score=14.095187
I20260812 06:19:50.294612 21335 maintenance_manager.cc:643] P d714efdbf43f453b814f75bdb8c5402b: FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c) complete. Timing: real 0.068s	user 0.032s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18770,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:50.295243 21423 maintenance_manager.cc:419] P d714efdbf43f453b814f75bdb8c5402b: Scheduling FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c): perf score=2.188937
I20260812 06:19:50.310448 21335 maintenance_manager.cc:643] P d714efdbf43f453b814f75bdb8c5402b: FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c) complete. Timing: real 0.015s	user 0.004s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5611,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:50.311064 21423 maintenance_manager.cc:419] P d714efdbf43f453b814f75bdb8c5402b: Scheduling MajorDeltaCompactionOp(f72a813222b74e73999298c72322a84c): perf score=1.000000
I20260812 06:19:50.476909 21335 maintenance_manager.cc:643] P d714efdbf43f453b814f75bdb8c5402b: MajorDeltaCompactionOp(f72a813222b74e73999298c72322a84c) complete. Timing: real 0.166s	user 0.148s	sys 0.017s 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":1162,"lbm_read_time_us":13506,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25726,"lbm_writes_lt_1ms":543,"mutex_wait_us":352,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10496,"update_count":2500}
I20260812 06:19:50.477545 21423 maintenance_manager.cc:419] P d714efdbf43f453b814f75bdb8c5402b: Scheduling FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c): perf score=10.126437
I20260812 06:19:50.516695 21335 maintenance_manager.cc:643] P d714efdbf43f453b814f75bdb8c5402b: FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c) complete. Timing: real 0.039s	user 0.018s	sys 0.013s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":14425,"lbm_writes_lt_1ms":303,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":1500}
I20260812 06:19:50.517385 21423 maintenance_manager.cc:419] P d714efdbf43f453b814f75bdb8c5402b: Scheduling FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c): perf score=2.188937
I20260812 06:19:50.533468 21335 maintenance_manager.cc:643] P d714efdbf43f453b814f75bdb8c5402b: FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c) complete. Timing: real 0.016s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5816,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:50.534080 21423 maintenance_manager.cc:419] P d714efdbf43f453b814f75bdb8c5402b: Scheduling MajorDeltaCompactionOp(f72a813222b74e73999298c72322a84c): perf score=1.000000
I20260812 06:19:50.672544 21335 maintenance_manager.cc:643] P d714efdbf43f453b814f75bdb8c5402b: MajorDeltaCompactionOp(f72a813222b74e73999298c72322a84c) complete. Timing: real 0.138s	user 0.111s	sys 0.017s 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":513,"lbm_read_time_us":8980,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21996,"lbm_writes_lt_1ms":443,"mutex_wait_us":287,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4096,"update_count":2000}
I20260812 06:19:50.673175 21423 maintenance_manager.cc:419] P d714efdbf43f453b814f75bdb8c5402b: Scheduling FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c): perf score=10.126437
I20260812 06:19:50.716850 21335 maintenance_manager.cc:643] P d714efdbf43f453b814f75bdb8c5402b: FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c) complete. Timing: real 0.044s	user 0.009s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13875,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:50.717449 21423 maintenance_manager.cc:419] P d714efdbf43f453b814f75bdb8c5402b: Scheduling FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c): perf score=2.188937
I20260812 06:19:50.733649 21335 maintenance_manager.cc:643] P d714efdbf43f453b814f75bdb8c5402b: FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c) complete. Timing: real 0.016s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5962,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:50.734287 21423 maintenance_manager.cc:419] P d714efdbf43f453b814f75bdb8c5402b: Scheduling FlushMRSOp(f72a813222b74e73999298c72322a84c): perf score=1.000000
I20260812 06:19:50.761893 21335 maintenance_manager.cc:643] P d714efdbf43f453b814f75bdb8c5402b: FlushMRSOp(f72a813222b74e73999298c72322a84c) complete. Timing: real 0.027s	user 0.027s	sys 0.000s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":71,"dirs.run_cpu_time_us":214,"dirs.run_wall_time_us":1734,"drs_written":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1574,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:50.762699 21423 maintenance_manager.cc:419] P d714efdbf43f453b814f75bdb8c5402b: Scheduling LogGCOp(f72a813222b74e73999298c72322a84c): free 132571583 bytes of WAL
I20260812 06:19:50.762976 21335 log_reader.cc:385] T f72a813222b74e73999298c72322a84c: removed 13 log segments from log reader
I20260812 06:19:50.763044 21335 log.cc:1079] T f72a813222b74e73999298c72322a84c P d714efdbf43f453b814f75bdb8c5402b: Deleting log segment in path: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585830708-21174-0/minicluster-data/ts-0-root/wals/f72a813222b74e73999298c72322a84c/wal-000000027 (ops 129-133)
I20260812 06:19:50.763087 21335 log.cc:1079] T f72a813222b74e73999298c72322a84c P d714efdbf43f453b814f75bdb8c5402b: Deleting log segment in path: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585830708-21174-0/minicluster-data/ts-0-root/wals/f72a813222b74e73999298c72322a84c/wal-000000028 (ops 134-138)
I20260812 06:19:50.763118 21335 log.cc:1079] T f72a813222b74e73999298c72322a84c P d714efdbf43f453b814f75bdb8c5402b: Deleting log segment in path: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585830708-21174-0/minicluster-data/ts-0-root/wals/f72a813222b74e73999298c72322a84c/wal-000000029 (ops 139-143)
I20260812 06:19:50.763152 21335 log.cc:1079] T f72a813222b74e73999298c72322a84c P d714efdbf43f453b814f75bdb8c5402b: Deleting log segment in path: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585830708-21174-0/minicluster-data/ts-0-root/wals/f72a813222b74e73999298c72322a84c/wal-000000030 (ops 144-148)
I20260812 06:19:50.763182 21335 log.cc:1079] T f72a813222b74e73999298c72322a84c P d714efdbf43f453b814f75bdb8c5402b: Deleting log segment in path: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585830708-21174-0/minicluster-data/ts-0-root/wals/f72a813222b74e73999298c72322a84c/wal-000000031 (ops 149-152)
I20260812 06:19:50.763207 21335 log.cc:1079] T f72a813222b74e73999298c72322a84c P d714efdbf43f453b814f75bdb8c5402b: Deleting log segment in path: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585830708-21174-0/minicluster-data/ts-0-root/wals/f72a813222b74e73999298c72322a84c/wal-000000032 (ops 153-157)
I20260812 06:19:50.763233 21335 log.cc:1079] T f72a813222b74e73999298c72322a84c P d714efdbf43f453b814f75bdb8c5402b: Deleting log segment in path: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585830708-21174-0/minicluster-data/ts-0-root/wals/f72a813222b74e73999298c72322a84c/wal-000000033 (ops 158-162)
I20260812 06:19:50.763259 21335 log.cc:1079] T f72a813222b74e73999298c72322a84c P d714efdbf43f453b814f75bdb8c5402b: Deleting log segment in path: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585830708-21174-0/minicluster-data/ts-0-root/wals/f72a813222b74e73999298c72322a84c/wal-000000034 (ops 163-166)
I20260812 06:19:50.763293 21335 log.cc:1079] T f72a813222b74e73999298c72322a84c P d714efdbf43f453b814f75bdb8c5402b: Deleting log segment in path: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585830708-21174-0/minicluster-data/ts-0-root/wals/f72a813222b74e73999298c72322a84c/wal-000000035 (ops 167-171)
I20260812 06:19:50.763324 21335 log.cc:1079] T f72a813222b74e73999298c72322a84c P d714efdbf43f453b814f75bdb8c5402b: Deleting log segment in path: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585830708-21174-0/minicluster-data/ts-0-root/wals/f72a813222b74e73999298c72322a84c/wal-000000036 (ops 172-176)
I20260812 06:19:50.763352 21335 log.cc:1079] T f72a813222b74e73999298c72322a84c P d714efdbf43f453b814f75bdb8c5402b: Deleting log segment in path: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585830708-21174-0/minicluster-data/ts-0-root/wals/f72a813222b74e73999298c72322a84c/wal-000000037 (ops 177-181)
I20260812 06:19:50.763382 21335 log.cc:1079] T f72a813222b74e73999298c72322a84c P d714efdbf43f453b814f75bdb8c5402b: Deleting log segment in path: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585830708-21174-0/minicluster-data/ts-0-root/wals/f72a813222b74e73999298c72322a84c/wal-000000038 (ops 182-186)
I20260812 06:19:50.763408 21335 log.cc:1079] T f72a813222b74e73999298c72322a84c P d714efdbf43f453b814f75bdb8c5402b: Deleting log segment in path: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515585830708-21174-0/minicluster-data/ts-0-root/wals/f72a813222b74e73999298c72322a84c/wal-000000039 (ops 187-191)
I20260812 06:19:50.792258 21335 maintenance_manager.cc:643] P d714efdbf43f453b814f75bdb8c5402b: LogGCOp(f72a813222b74e73999298c72322a84c) complete. Timing: real 0.029s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:19:50.792768 21423 maintenance_manager.cc:419] P d714efdbf43f453b814f75bdb8c5402b: Scheduling UndoDeltaBlockGCOp(f72a813222b74e73999298c72322a84c): 482 bytes on disk
I20260812 06:19:50.793392 21335 maintenance_manager.cc:643] P d714efdbf43f453b814f75bdb8c5402b: UndoDeltaBlockGCOp(f72a813222b74e73999298c72322a84c) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":94,"lbm_reads_lt_1ms":4}
I20260812 06:19:50.794057 21423 maintenance_manager.cc:419] P d714efdbf43f453b814f75bdb8c5402b: Scheduling FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c): perf score=3.181125
I20260812 06:19:50.806071 21335 maintenance_manager.cc:643] P d714efdbf43f453b814f75bdb8c5402b: FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4635978,"delete_count":0,"lbm_write_time_us":4536,"lbm_writes_lt_1ms":116,"reinsert_count":0,"update_count":565}
I20260812 06:19:50.806592 21423 maintenance_manager.cc:419] P d714efdbf43f453b814f75bdb8c5402b: Scheduling FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c): perf score=2.188937
I20260812 06:19:50.816711 21335 maintenance_manager.cc:643] P d714efdbf43f453b814f75bdb8c5402b: FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c) complete. Timing: real 0.010s	user 0.007s	sys 0.001s Metrics: {"bytes_written":3569330,"delete_count":0,"lbm_write_time_us":3363,"lbm_writes_lt_1ms":90,"reinsert_count":0,"update_count":435}
I20260812 06:19:50.817847 21423 maintenance_manager.cc:419] P d714efdbf43f453b814f75bdb8c5402b: Scheduling MajorDeltaCompactionOp(f72a813222b74e73999298c72322a84c): perf score=1.000000
I20260812 06:19:50.942790 21174 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.831s	user 1.739s	sys 0.137s
I20260812 06:19:50.984916 21335 maintenance_manager.cc:643] P d714efdbf43f453b814f75bdb8c5402b: MajorDeltaCompactionOp(f72a813222b74e73999298c72322a84c) complete. Timing: real 0.167s	user 0.125s	sys 0.040s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877328,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"lbm_read_time_us":11204,"lbm_reads_lt_1ms":670,"lbm_write_time_us":34241,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"update_count":3000}
I20260812 06:19:50.985488 21423 maintenance_manager.cc:419] P d714efdbf43f453b814f75bdb8c5402b: Scheduling FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c): perf score=10.126437
I20260812 06:19:51.015257 21174 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.072s	user 0.002s	sys 0.000s
I20260812 06:19:51.015929 21174 tablet_server.cc:179] TabletServer@127.20.173.129:0 shutting down...
I20260812 06:19:51.016920 21335 maintenance_manager.cc:643] P d714efdbf43f453b814f75bdb8c5402b: FlushDeltaMemStoresOp(f72a813222b74e73999298c72322a84c) complete. Timing: real 0.031s	user 0.019s	sys 0.009s Metrics: {"bytes_written":12307495,"delete_count":0,"lbm_write_time_us":13322,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:51.017426 21423 maintenance_manager.cc:419] P d714efdbf43f453b814f75bdb8c5402b: Scheduling MajorDeltaCompactionOp(f72a813222b74e73999298c72322a84c): perf score=1.000000
I20260812 06:19:51.111410 21335 maintenance_manager.cc:643] P d714efdbf43f453b814f75bdb8c5402b: MajorDeltaCompactionOp(f72a813222b74e73999298c72322a84c) complete. Timing: real 0.094s	user 0.054s	sys 0.040s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16569751,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":446,"lbm_read_time_us":6315,"lbm_reads_lt_1ms":367,"lbm_write_time_us":16437,"lbm_writes_lt_1ms":343,"mutex_wait_us":66,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":160128,"update_count":1500}
I20260812 06:19:51.112231 21174 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:51.112721 21174 tablet_replica.cc:333] T f72a813222b74e73999298c72322a84c P d714efdbf43f453b814f75bdb8c5402b: stopping tablet replica
I20260812 06:19:51.113000 21174 raft_consensus.cc:2243] T f72a813222b74e73999298c72322a84c P d714efdbf43f453b814f75bdb8c5402b [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:51.113310 21174 raft_consensus.cc:2272] T f72a813222b74e73999298c72322a84c P d714efdbf43f453b814f75bdb8c5402b [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:51.129024 21174 tablet_server.cc:196] TabletServer@127.20.173.129:0 shutdown complete.
I20260812 06:19:51.145742 21174 master.cc:562] Master@127.20.173.190:36395 shutting down...
I20260812 06:19:51.149245 21174 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 8d537737f0434cbea620dd33e6e6c49d [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:51.149443 21174 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 8d537737f0434cbea620dd33e6e6c49d [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:51.149518 21174 tablet_replica.cc:333] T 00000000000000000000000000000000 P 8d537737f0434cbea620dd33e6e6c49d: stopping tablet replica
I20260812 06:19:51.161813 21174 master.cc:584] Master@127.20.173.190:36395 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5397 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:19:51.238969 21174 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.20.173.190:39817
I20260812 06:19:51.239377 21174 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:51.241323 21473 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:51.241451 21469 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:51.241609 21174 server_base.cc:1061] running on GCE node
W20260812 06:19:51.241488 21467 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:51.241915 21174 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:51.241961 21174 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:51.241976 21174 hybrid_clock.cc:648] HybridClock initialized: now 1786515591241975 us; error 0 us; skew 500 ppm
I20260812 06:19:51.242810 21174 webserver.cc:533] Webserver started at http://127.20.173.190:46161/ using document root <none> and password file <none>
I20260812 06:19:51.242978 21174 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:51.243027 21174 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:51.243089 21174 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:51.243464 21174 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585830708-21174-0/minicluster-data/master-0-root/instance:
uuid: "d26d2e682fd941159a033d25af1477d1"
format_stamp: "Formatted at 2026-08-12 06:19:51 on dist-test-slave-rmhg"
I20260812 06:19:51.245031 21174 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:51.246232 21482 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:51.246575 21174 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:51.246649 21174 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585830708-21174-0/minicluster-data/master-0-root
uuid: "d26d2e682fd941159a033d25af1477d1"
format_stamp: "Formatted at 2026-08-12 06:19:51 on dist-test-slave-rmhg"
I20260812 06:19:51.246729 21174 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585830708-21174-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585830708-21174-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585830708-21174-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:51.266389 21174 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:51.266813 21174 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:51.271106 21174 rpc_server.cc:307] RPC server started. Bound to: 127.20.173.190:39817
I20260812 06:19:51.276069 21559 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.20.173.190:39817 every 8 connection(s)
I20260812 06:19:51.281062 21560 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:51.283221 21560 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P d26d2e682fd941159a033d25af1477d1: Bootstrap starting.
I20260812 06:19:51.284073 21560 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P d26d2e682fd941159a033d25af1477d1: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:51.285423 21560 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P d26d2e682fd941159a033d25af1477d1: No bootstrap required, opened a new log
I20260812 06:19:51.285938 21560 raft_consensus.cc:359] T 00000000000000000000000000000000 P d26d2e682fd941159a033d25af1477d1 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d26d2e682fd941159a033d25af1477d1" member_type: VOTER }
I20260812 06:19:51.286043 21560 raft_consensus.cc:385] T 00000000000000000000000000000000 P d26d2e682fd941159a033d25af1477d1 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:51.286065 21560 raft_consensus.cc:740] T 00000000000000000000000000000000 P d26d2e682fd941159a033d25af1477d1 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: d26d2e682fd941159a033d25af1477d1, State: Initialized, Role: FOLLOWER
I20260812 06:19:51.286204 21560 consensus_queue.cc:260] T 00000000000000000000000000000000 P d26d2e682fd941159a033d25af1477d1 [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: "d26d2e682fd941159a033d25af1477d1" member_type: VOTER }
I20260812 06:19:51.286281 21560 raft_consensus.cc:399] T 00000000000000000000000000000000 P d26d2e682fd941159a033d25af1477d1 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:51.286316 21560 raft_consensus.cc:493] T 00000000000000000000000000000000 P d26d2e682fd941159a033d25af1477d1 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:51.286367 21560 raft_consensus.cc:3060] T 00000000000000000000000000000000 P d26d2e682fd941159a033d25af1477d1 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:51.287107 21560 raft_consensus.cc:515] T 00000000000000000000000000000000 P d26d2e682fd941159a033d25af1477d1 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d26d2e682fd941159a033d25af1477d1" member_type: VOTER }
I20260812 06:19:51.287236 21560 leader_election.cc:304] T 00000000000000000000000000000000 P d26d2e682fd941159a033d25af1477d1 [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: d26d2e682fd941159a033d25af1477d1; no voters: 
I20260812 06:19:51.287493 21560 leader_election.cc:290] T 00000000000000000000000000000000 P d26d2e682fd941159a033d25af1477d1 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:51.287614 21566 raft_consensus.cc:2804] T 00000000000000000000000000000000 P d26d2e682fd941159a033d25af1477d1 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:51.287806 21566 raft_consensus.cc:697] T 00000000000000000000000000000000 P d26d2e682fd941159a033d25af1477d1 [term 1 LEADER]: Becoming Leader. State: Replica: d26d2e682fd941159a033d25af1477d1, State: Running, Role: LEADER
I20260812 06:19:51.287971 21560 sys_catalog.cc:565] T 00000000000000000000000000000000 P d26d2e682fd941159a033d25af1477d1 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:51.287949 21566 consensus_queue.cc:237] T 00000000000000000000000000000000 P d26d2e682fd941159a033d25af1477d1 [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: "d26d2e682fd941159a033d25af1477d1" member_type: VOTER }
I20260812 06:19:51.288538 21567 sys_catalog.cc:455] T 00000000000000000000000000000000 P d26d2e682fd941159a033d25af1477d1 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "d26d2e682fd941159a033d25af1477d1" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d26d2e682fd941159a033d25af1477d1" member_type: VOTER } }
I20260812 06:19:51.288573 21568 sys_catalog.cc:455] T 00000000000000000000000000000000 P d26d2e682fd941159a033d25af1477d1 [sys.catalog]: SysCatalogTable state changed. Reason: New leader d26d2e682fd941159a033d25af1477d1. Latest consensus state: current_term: 1 leader_uuid: "d26d2e682fd941159a033d25af1477d1" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "d26d2e682fd941159a033d25af1477d1" member_type: VOTER } }
I20260812 06:19:51.288640 21567 sys_catalog.cc:458] T 00000000000000000000000000000000 P d26d2e682fd941159a033d25af1477d1 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:51.288677 21568 sys_catalog.cc:458] T 00000000000000000000000000000000 P d26d2e682fd941159a033d25af1477d1 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:51.288976 21573 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:51.289940 21573 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:51.290161 21174 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:51.291872 21573 catalog_manager.cc:1383] Generated new cluster ID: b31c816801854f46838005c696385f91
I20260812 06:19:51.291946 21573 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:51.296828 21573 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:51.297452 21573 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:51.301745 21573 catalog_manager.cc:6092] T 00000000000000000000000000000000 P d26d2e682fd941159a033d25af1477d1: Generated new TSK 0
I20260812 06:19:51.301951 21573 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:51.306550 21174 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:51.308615 21600 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:51.308585 21597 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:51.308683 21174 server_base.cc:1061] running on GCE node
W20260812 06:19:51.308591 21596 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:51.308993 21174 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:51.309059 21174 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:51.309077 21174 hybrid_clock.cc:648] HybridClock initialized: now 1786515591309076 us; error 0 us; skew 500 ppm
I20260812 06:19:51.309901 21174 webserver.cc:533] Webserver started at http://127.20.173.129:33341/ using document root <none> and password file <none>
I20260812 06:19:51.310084 21174 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:51.310139 21174 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:51.310201 21174 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:51.310608 21174 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585830708-21174-0/minicluster-data/ts-0-root/instance:
uuid: "e042ff8ff313458abebe030f9121dae6"
format_stamp: "Formatted at 2026-08-12 06:19:51 on dist-test-slave-rmhg"
I20260812 06:19:51.312129 21174 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:51.313088 21607 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:51.313346 21174 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:51.313417 21174 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585830708-21174-0/minicluster-data/ts-0-root
uuid: "e042ff8ff313458abebe030f9121dae6"
format_stamp: "Formatted at 2026-08-12 06:19:51 on dist-test-slave-rmhg"
I20260812 06:19:51.313494 21174 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585830708-21174-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585830708-21174-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585830708-21174-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:51.324703 21174 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:51.325243 21174 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:51.325598 21174 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:51.326121 21174 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:51.326161 21174 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:51.326210 21174 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:51.326239 21174 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:51.330546 21174 rpc_server.cc:307] RPC server started. Bound to: 127.20.173.129:43759
I20260812 06:19:51.330570 21713 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.20.173.129:43759 every 8 connection(s)
I20260812 06:19:51.338634 21716 heartbeater.cc:344] Connected to a master server at 127.20.173.190:39817
I20260812 06:19:51.338770 21716 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:51.339069 21716 heartbeater.cc:507] Master 127.20.173.190:39817 requested a full tablet report, sending...
I20260812 06:19:51.339756 21506 ts_manager.cc:194] Registered new tserver with Master: e042ff8ff313458abebe030f9121dae6 (127.20.173.129:43759)
I20260812 06:19:51.339924 21174 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.008959885s
I20260812 06:19:51.340580 21506 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:34118
I20260812 06:19:51.347324 21506 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:34132:
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:51.356058 21649 tablet_service.cc:1511] Processing CreateTablet for tablet cdaa3d4df8e6417a8bc97979222734de (DEFAULT_TABLE table=heavy-update-compaction-test [id=b033a3274a7c4610afcd625b3a7a79ef]), partition=
I20260812 06:19:51.356346 21649 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet cdaa3d4df8e6417a8bc97979222734de. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:51.358382 21732 tablet_bootstrap.cc:492] T cdaa3d4df8e6417a8bc97979222734de P e042ff8ff313458abebe030f9121dae6: Bootstrap starting.
I20260812 06:19:51.359380 21732 tablet_bootstrap.cc:654] T cdaa3d4df8e6417a8bc97979222734de P e042ff8ff313458abebe030f9121dae6: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:51.360507 21732 tablet_bootstrap.cc:492] T cdaa3d4df8e6417a8bc97979222734de P e042ff8ff313458abebe030f9121dae6: No bootstrap required, opened a new log
I20260812 06:19:51.360599 21732 ts_tablet_manager.cc:1403] T cdaa3d4df8e6417a8bc97979222734de P e042ff8ff313458abebe030f9121dae6: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:51.361043 21732 raft_consensus.cc:359] T cdaa3d4df8e6417a8bc97979222734de P e042ff8ff313458abebe030f9121dae6 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e042ff8ff313458abebe030f9121dae6" member_type: VOTER last_known_addr { host: "127.20.173.129" port: 43759 } }
I20260812 06:19:51.361145 21732 raft_consensus.cc:385] T cdaa3d4df8e6417a8bc97979222734de P e042ff8ff313458abebe030f9121dae6 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:51.361183 21732 raft_consensus.cc:740] T cdaa3d4df8e6417a8bc97979222734de P e042ff8ff313458abebe030f9121dae6 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: e042ff8ff313458abebe030f9121dae6, State: Initialized, Role: FOLLOWER
I20260812 06:19:51.361307 21732 consensus_queue.cc:260] T cdaa3d4df8e6417a8bc97979222734de P e042ff8ff313458abebe030f9121dae6 [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: "e042ff8ff313458abebe030f9121dae6" member_type: VOTER last_known_addr { host: "127.20.173.129" port: 43759 } }
I20260812 06:19:51.361398 21732 raft_consensus.cc:399] T cdaa3d4df8e6417a8bc97979222734de P e042ff8ff313458abebe030f9121dae6 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:51.361431 21732 raft_consensus.cc:493] T cdaa3d4df8e6417a8bc97979222734de P e042ff8ff313458abebe030f9121dae6 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:51.361470 21732 raft_consensus.cc:3060] T cdaa3d4df8e6417a8bc97979222734de P e042ff8ff313458abebe030f9121dae6 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:51.362432 21732 raft_consensus.cc:515] T cdaa3d4df8e6417a8bc97979222734de P e042ff8ff313458abebe030f9121dae6 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e042ff8ff313458abebe030f9121dae6" member_type: VOTER last_known_addr { host: "127.20.173.129" port: 43759 } }
I20260812 06:19:51.362572 21732 leader_election.cc:304] T cdaa3d4df8e6417a8bc97979222734de P e042ff8ff313458abebe030f9121dae6 [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: e042ff8ff313458abebe030f9121dae6; no voters: 
I20260812 06:19:51.362749 21732 leader_election.cc:290] T cdaa3d4df8e6417a8bc97979222734de P e042ff8ff313458abebe030f9121dae6 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:51.362888 21734 raft_consensus.cc:2804] T cdaa3d4df8e6417a8bc97979222734de P e042ff8ff313458abebe030f9121dae6 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:51.363097 21734 raft_consensus.cc:697] T cdaa3d4df8e6417a8bc97979222734de P e042ff8ff313458abebe030f9121dae6 [term 1 LEADER]: Becoming Leader. State: Replica: e042ff8ff313458abebe030f9121dae6, State: Running, Role: LEADER
I20260812 06:19:51.363199 21716 heartbeater.cc:499] Master 127.20.173.190:39817 was elected leader, sending a full tablet report...
I20260812 06:19:51.363124 21732 ts_tablet_manager.cc:1434] T cdaa3d4df8e6417a8bc97979222734de P e042ff8ff313458abebe030f9121dae6: Time spent starting tablet: real 0.002s	user 0.000s	sys 0.003s
I20260812 06:19:51.363322 21734 consensus_queue.cc:237] T cdaa3d4df8e6417a8bc97979222734de P e042ff8ff313458abebe030f9121dae6 [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: "e042ff8ff313458abebe030f9121dae6" member_type: VOTER last_known_addr { host: "127.20.173.129" port: 43759 } }
I20260812 06:19:51.364671 21506 catalog_manager.cc:5719] T cdaa3d4df8e6417a8bc97979222734de P e042ff8ff313458abebe030f9121dae6 reported cstate change: term changed from 0 to 1, leader changed from <none> to e042ff8ff313458abebe030f9121dae6 (127.20.173.129). New cstate: current_term: 1 leader_uuid: "e042ff8ff313458abebe030f9121dae6" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e042ff8ff313458abebe030f9121dae6" member_type: VOTER last_known_addr { host: "127.20.173.129" port: 43759 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:51.425011 21174 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.052s	user 0.006s	sys 0.017s
I20260812 06:19:51.581413 21717 maintenance_manager.cc:419] P e042ff8ff313458abebe030f9121dae6: Scheduling FlushMRSOp(cdaa3d4df8e6417a8bc97979222734de): perf score=19.054940
I20260812 06:19:51.739137 21614 maintenance_manager.cc:643] P e042ff8ff313458abebe030f9121dae6: FlushMRSOp(cdaa3d4df8e6417a8bc97979222734de) complete. Timing: real 0.157s	user 0.107s	sys 0.049s Metrics: {"bytes_written":12307490,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":44,"dirs.run_cpu_time_us":225,"dirs.run_wall_time_us":864,"drs_written":1,"lbm_read_time_us":68,"lbm_reads_lt_1ms":4,"lbm_write_time_us":41190,"lbm_writes_lt_1ms":767,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"update_count":1500}
I20260812 06:19:51.739898 21717 maintenance_manager.cc:419] P e042ff8ff313458abebe030f9121dae6: Scheduling LogGCOp(cdaa3d4df8e6417a8bc97979222734de): free 20743880 bytes of WAL
I20260812 06:19:51.740159 21614 log_reader.cc:385] T cdaa3d4df8e6417a8bc97979222734de: removed 2 log segments from log reader
I20260812 06:19:51.740226 21614 log.cc:1079] T cdaa3d4df8e6417a8bc97979222734de P e042ff8ff313458abebe030f9121dae6: Deleting log segment in path: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585830708-21174-0/minicluster-data/ts-0-root/wals/cdaa3d4df8e6417a8bc97979222734de/wal-000000001 (ops 1-6)
I20260812 06:19:51.740269 21614 log.cc:1079] T cdaa3d4df8e6417a8bc97979222734de P e042ff8ff313458abebe030f9121dae6: Deleting log segment in path: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585830708-21174-0/minicluster-data/ts-0-root/wals/cdaa3d4df8e6417a8bc97979222734de/wal-000000002 (ops 7-11)
I20260812 06:19:51.744721 21614 maintenance_manager.cc:643] P e042ff8ff313458abebe030f9121dae6: LogGCOp(cdaa3d4df8e6417a8bc97979222734de) complete. Timing: real 0.005s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:19:51.745124 21717 maintenance_manager.cc:419] P e042ff8ff313458abebe030f9121dae6: Scheduling UndoDeltaBlockGCOp(cdaa3d4df8e6417a8bc97979222734de): 16821649 bytes on disk
I20260812 06:19:51.745597 21614 maintenance_manager.cc:643] P e042ff8ff313458abebe030f9121dae6: UndoDeltaBlockGCOp(cdaa3d4df8e6417a8bc97979222734de) 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:51.746312 21717 maintenance_manager.cc:419] P e042ff8ff313458abebe030f9121dae6: Scheduling FlushDeltaMemStoresOp(cdaa3d4df8e6417a8bc97979222734de): perf score=2.188937
I20260812 06:19:51.771457 21614 maintenance_manager.cc:643] P e042ff8ff313458abebe030f9121dae6: FlushDeltaMemStoresOp(cdaa3d4df8e6417a8bc97979222734de) complete. Timing: real 0.025s	user 0.006s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4571,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:51.771961 21717 maintenance_manager.cc:419] P e042ff8ff313458abebe030f9121dae6: Scheduling FlushDeltaMemStoresOp(cdaa3d4df8e6417a8bc97979222734de): perf score=2.188937
I20260812 06:19:51.782401 21614 maintenance_manager.cc:643] P e042ff8ff313458abebe030f9121dae6: FlushDeltaMemStoresOp(cdaa3d4df8e6417a8bc97979222734de) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3678,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:51.783102 21717 maintenance_manager.cc:419] P e042ff8ff313458abebe030f9121dae6: Scheduling MajorDeltaCompactionOp(cdaa3d4df8e6417a8bc97979222734de): perf score=1.000000
I20260812 06:19:51.954811 21614 maintenance_manager.cc:643] P e042ff8ff313458abebe030f9121dae6: MajorDeltaCompactionOp(cdaa3d4df8e6417a8bc97979222734de) complete. Timing: real 0.171s	user 0.128s	sys 0.034s Metrics: {"cfile_cache_miss":523,"cfile_cache_miss_bytes":24405549,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":530,"lbm_read_time_us":13040,"lbm_reads_lt_1ms":559,"lbm_write_time_us":27557,"lbm_writes_lt_1ms":533,"peak_mem_usage":61665166,"reinsert_count":0,"spinlock_wait_cycles":2560,"thread_start_us":314,"threads_started":5,"update_count":2450}
I20260812 06:19:51.955420 21717 maintenance_manager.cc:419] P e042ff8ff313458abebe030f9121dae6: Scheduling FlushDeltaMemStoresOp(cdaa3d4df8e6417a8bc97979222734de): perf score=14.095187
I20260812 06:19:52.007625 21614 maintenance_manager.cc:643] P e042ff8ff313458abebe030f9121dae6: FlushDeltaMemStoresOp(cdaa3d4df8e6417a8bc97979222734de) complete. Timing: real 0.052s	user 0.029s	sys 0.013s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19486,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:52.008224 21717 maintenance_manager.cc:419] P e042ff8ff313458abebe030f9121dae6: Scheduling FlushDeltaMemStoresOp(cdaa3d4df8e6417a8bc97979222734de): perf score=2.188937
I20260812 06:19:52.019732 21614 maintenance_manager.cc:643] P e042ff8ff313458abebe030f9121dae6: FlushDeltaMemStoresOp(cdaa3d4df8e6417a8bc97979222734de) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3946,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:52.020215 21717 maintenance_manager.cc:419] P e042ff8ff313458abebe030f9121dae6: Scheduling MajorDeltaCompactionOp(cdaa3d4df8e6417a8bc97979222734de): perf score=1.000000
I20260812 06:19:52.165974 21614 maintenance_manager.cc:643] P e042ff8ff313458abebe030f9121dae6: MajorDeltaCompactionOp(cdaa3d4df8e6417a8bc97979222734de) complete. Timing: real 0.146s	user 0.094s	sys 0.051s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":147,"lbm_read_time_us":10021,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27106,"lbm_writes_lt_1ms":543,"mutex_wait_us":48,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":2500}
I20260812 06:19:52.166574 21717 maintenance_manager.cc:419] P e042ff8ff313458abebe030f9121dae6: Scheduling FlushDeltaMemStoresOp(cdaa3d4df8e6417a8bc97979222734de): perf score=10.126437
I20260812 06:19:52.196660 21614 maintenance_manager.cc:643] P e042ff8ff313458abebe030f9121dae6: FlushDeltaMemStoresOp(cdaa3d4df8e6417a8bc97979222734de) complete. Timing: real 0.030s	user 0.023s	sys 0.004s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":12929,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:52.197281 21717 maintenance_manager.cc:419] P e042ff8ff313458abebe030f9121dae6: Scheduling FlushDeltaMemStoresOp(cdaa3d4df8e6417a8bc97979222734de): perf score=2.188937
I20260812 06:19:52.214499 21614 maintenance_manager.cc:643] P e042ff8ff313458abebe030f9121dae6: FlushDeltaMemStoresOp(cdaa3d4df8e6417a8bc97979222734de) complete. Timing: real 0.017s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5532,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:52.215035 21717 maintenance_manager.cc:419] P e042ff8ff313458abebe030f9121dae6: Scheduling MajorDeltaCompactionOp(cdaa3d4df8e6417a8bc97979222734de): perf score=1.000000
I20260812 06:19:52.367690 21614 maintenance_manager.cc:643] P e042ff8ff313458abebe030f9121dae6: MajorDeltaCompactionOp(cdaa3d4df8e6417a8bc97979222734de) complete. Timing: real 0.152s	user 0.101s	sys 0.046s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713275,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":780,"lbm_read_time_us":10812,"lbm_reads_lt_1ms":468,"lbm_write_time_us":24604,"lbm_writes_lt_1ms":443,"mutex_wait_us":281,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2000}
I20260812 06:19:52.368265 21717 maintenance_manager.cc:419] P e042ff8ff313458abebe030f9121dae6: Scheduling FlushDeltaMemStoresOp(cdaa3d4df8e6417a8bc97979222734de): perf score=11.118625
I20260812 06:19:52.405097 21614 maintenance_manager.cc:643] P e042ff8ff313458abebe030f9121dae6: FlushDeltaMemStoresOp(cdaa3d4df8e6417a8bc97979222734de) complete. Timing: real 0.037s	user 0.027s	sys 0.005s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15105,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:52.405725 21717 maintenance_manager.cc:419] P e042ff8ff313458abebe030f9121dae6: Scheduling FlushDeltaMemStoresOp(cdaa3d4df8e6417a8bc97979222734de): perf score=2.188937
I20260812 06:19:52.440478 21614 maintenance_manager.cc:643] P e042ff8ff313458abebe030f9121dae6: FlushDeltaMemStoresOp(cdaa3d4df8e6417a8bc97979222734de) complete. Timing: real 0.033s	user 0.000s	sys 0.019s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4971,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:52.441053 21717 maintenance_manager.cc:419] P e042ff8ff313458abebe030f9121dae6: Scheduling FlushDeltaMemStoresOp(cdaa3d4df8e6417a8bc97979222734de): perf score=2.188937
I20260812 06:19:52.451735 21614 maintenance_manager.cc:643] P e042ff8ff313458abebe030f9121dae6: FlushDeltaMemStoresOp(cdaa3d4df8e6417a8bc97979222734de) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4080,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:52.452333 21717 maintenance_manager.cc:419] P e042ff8ff313458abebe030f9121dae6: Scheduling MajorDeltaCompactionOp(cdaa3d4df8e6417a8bc97979222734de): perf score=1.000000
I20260812 06:19:52.642827 21614 maintenance_manager.cc:643] P e042ff8ff313458abebe030f9121dae6: MajorDeltaCompactionOp(cdaa3d4df8e6417a8bc97979222734de) complete. Timing: real 0.190s	user 0.114s	sys 0.064s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815793,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":325,"lbm_read_time_us":12557,"lbm_reads_lt_1ms":573,"lbm_write_time_us":28781,"lbm_writes_lt_1ms":543,"mutex_wait_us":44,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10368,"update_count":2500}
I20260812 06:19:52.643481 21717 maintenance_manager.cc:419] P e042ff8ff313458abebe030f9121dae6: Scheduling FlushDeltaMemStoresOp(cdaa3d4df8e6417a8bc97979222734de): perf score=14.095187
I20260812 06:19:52.692066 21614 maintenance_manager.cc:643] P e042ff8ff313458abebe030f9121dae6: FlushDeltaMemStoresOp(cdaa3d4df8e6417a8bc97979222734de) complete. Timing: real 0.048s	user 0.023s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18262,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:52.692576 21717 maintenance_manager.cc:419] P e042ff8ff313458abebe030f9121dae6: Scheduling FlushDeltaMemStoresOp(cdaa3d4df8e6417a8bc97979222734de): perf score=2.188937
I20260812 06:19:52.703970 21614 maintenance_manager.cc:643] P e042ff8ff313458abebe030f9121dae6: FlushDeltaMemStoresOp(cdaa3d4df8e6417a8bc97979222734de) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4034,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:52.704670 21717 maintenance_manager.cc:419] P e042ff8ff313458abebe030f9121dae6: Scheduling MajorDeltaCompactionOp(cdaa3d4df8e6417a8bc97979222734de): perf score=1.000000
I20260812 06:19:52.908970 21614 maintenance_manager.cc:643] P e042ff8ff313458abebe030f9121dae6: MajorDeltaCompactionOp(cdaa3d4df8e6417a8bc97979222734de) complete. Timing: real 0.204s	user 0.105s	sys 0.085s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":919,"lbm_read_time_us":11649,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32894,"lbm_writes_lt_1ms":543,"mutex_wait_us":304,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5376,"update_count":2500}
I20260812 06:19:52.909685 21717 maintenance_manager.cc:419] P e042ff8ff313458abebe030f9121dae6: Scheduling FlushDeltaMemStoresOp(cdaa3d4df8e6417a8bc97979222734de): perf score=14.095187
I20260812 06:19:52.958277 21614 maintenance_manager.cc:643] P e042ff8ff313458abebe030f9121dae6: FlushDeltaMemStoresOp(cdaa3d4df8e6417a8bc97979222734de) complete. Timing: real 0.048s	user 0.028s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22080,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:19:52.958794 21717 maintenance_manager.cc:419] P e042ff8ff313458abebe030f9121dae6: Scheduling FlushDeltaMemStoresOp(cdaa3d4df8e6417a8bc97979222734de): perf score=2.188937
I20260812 06:19:52.974397 21614 maintenance_manager.cc:643] P e042ff8ff313458abebe030f9121dae6: FlushDeltaMemStoresOp(cdaa3d4df8e6417a8bc97979222734de) complete. Timing: real 0.015s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5610,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:52.975186 21717 maintenance_manager.cc:419] P e042ff8ff313458abebe030f9121dae6: Scheduling FlushMRSOp(cdaa3d4df8e6417a8bc97979222734de): perf score=1.000000
I20260812 06:19:53.005797 21614 maintenance_manager.cc:643] P e042ff8ff313458abebe030f9121dae6: FlushMRSOp(cdaa3d4df8e6417a8bc97979222734de) complete. Timing: real 0.030s	user 0.026s	sys 0.004s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":73,"dirs.run_cpu_time_us":258,"dirs.run_wall_time_us":1252,"drs_written":1,"lbm_read_time_us":42,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1340,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:53.006688 21717 maintenance_manager.cc:419] P e042ff8ff313458abebe030f9121dae6: Scheduling LogGCOp(cdaa3d4df8e6417a8bc97979222734de): free 112692365 bytes of WAL
I20260812 06:19:53.007017 21614 log_reader.cc:385] T cdaa3d4df8e6417a8bc97979222734de: removed 11 log segments from log reader
I20260812 06:19:53.007079 21614 log.cc:1079] T cdaa3d4df8e6417a8bc97979222734de P e042ff8ff313458abebe030f9121dae6: Deleting log segment in path: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585830708-21174-0/minicluster-data/ts-0-root/wals/cdaa3d4df8e6417a8bc97979222734de/wal-000000003 (ops 12-16)
I20260812 06:19:53.007123 21614 log.cc:1079] T cdaa3d4df8e6417a8bc97979222734de P e042ff8ff313458abebe030f9121dae6: Deleting log segment in path: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585830708-21174-0/minicluster-data/ts-0-root/wals/cdaa3d4df8e6417a8bc97979222734de/wal-000000004 (ops 17-21)
I20260812 06:19:53.007170 21614 log.cc:1079] T cdaa3d4df8e6417a8bc97979222734de P e042ff8ff313458abebe030f9121dae6: Deleting log segment in path: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585830708-21174-0/minicluster-data/ts-0-root/wals/cdaa3d4df8e6417a8bc97979222734de/wal-000000005 (ops 22-26)
I20260812 06:19:53.007201 21614 log.cc:1079] T cdaa3d4df8e6417a8bc97979222734de P e042ff8ff313458abebe030f9121dae6: Deleting log segment in path: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585830708-21174-0/minicluster-data/ts-0-root/wals/cdaa3d4df8e6417a8bc97979222734de/wal-000000006 (ops 27-31)
I20260812 06:19:53.007227 21614 log.cc:1079] T cdaa3d4df8e6417a8bc97979222734de P e042ff8ff313458abebe030f9121dae6: Deleting log segment in path: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585830708-21174-0/minicluster-data/ts-0-root/wals/cdaa3d4df8e6417a8bc97979222734de/wal-000000007 (ops 32-36)
I20260812 06:19:53.007259 21614 log.cc:1079] T cdaa3d4df8e6417a8bc97979222734de P e042ff8ff313458abebe030f9121dae6: Deleting log segment in path: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585830708-21174-0/minicluster-data/ts-0-root/wals/cdaa3d4df8e6417a8bc97979222734de/wal-000000008 (ops 37-41)
I20260812 06:19:53.007290 21614 log.cc:1079] T cdaa3d4df8e6417a8bc97979222734de P e042ff8ff313458abebe030f9121dae6: Deleting log segment in path: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585830708-21174-0/minicluster-data/ts-0-root/wals/cdaa3d4df8e6417a8bc97979222734de/wal-000000009 (ops 42-46)
I20260812 06:19:53.007321 21614 log.cc:1079] T cdaa3d4df8e6417a8bc97979222734de P e042ff8ff313458abebe030f9121dae6: Deleting log segment in path: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585830708-21174-0/minicluster-data/ts-0-root/wals/cdaa3d4df8e6417a8bc97979222734de/wal-000000010 (ops 47-51)
I20260812 06:19:53.007354 21614 log.cc:1079] T cdaa3d4df8e6417a8bc97979222734de P e042ff8ff313458abebe030f9121dae6: Deleting log segment in path: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585830708-21174-0/minicluster-data/ts-0-root/wals/cdaa3d4df8e6417a8bc97979222734de/wal-000000011 (ops 52-56)
I20260812 06:19:53.007385 21614 log.cc:1079] T cdaa3d4df8e6417a8bc97979222734de P e042ff8ff313458abebe030f9121dae6: Deleting log segment in path: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585830708-21174-0/minicluster-data/ts-0-root/wals/cdaa3d4df8e6417a8bc97979222734de/wal-000000012 (ops 57-61)
I20260812 06:19:53.007416 21614 log.cc:1079] T cdaa3d4df8e6417a8bc97979222734de P e042ff8ff313458abebe030f9121dae6: Deleting log segment in path: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585830708-21174-0/minicluster-data/ts-0-root/wals/cdaa3d4df8e6417a8bc97979222734de/wal-000000013 (ops 62-66)
I20260812 06:19:53.031504 21614 maintenance_manager.cc:643] P e042ff8ff313458abebe030f9121dae6: LogGCOp(cdaa3d4df8e6417a8bc97979222734de) complete. Timing: real 0.025s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:19:53.032097 21717 maintenance_manager.cc:419] P e042ff8ff313458abebe030f9121dae6: Scheduling UndoDeltaBlockGCOp(cdaa3d4df8e6417a8bc97979222734de): 462 bytes on disk
I20260812 06:19:53.032692 21614 maintenance_manager.cc:643] P e042ff8ff313458abebe030f9121dae6: UndoDeltaBlockGCOp(cdaa3d4df8e6417a8bc97979222734de) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":66,"lbm_reads_lt_1ms":4}
I20260812 06:19:53.033398 21717 maintenance_manager.cc:419] P e042ff8ff313458abebe030f9121dae6: Scheduling FlushDeltaMemStoresOp(cdaa3d4df8e6417a8bc97979222734de): perf score=3.181125
I20260812 06:19:53.058458 21614 maintenance_manager.cc:643] P e042ff8ff313458abebe030f9121dae6: FlushDeltaMemStoresOp(cdaa3d4df8e6417a8bc97979222734de) complete. Timing: real 0.025s	user 0.004s	sys 0.009s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":5323,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:53.058998 21717 maintenance_manager.cc:419] P e042ff8ff313458abebe030f9121dae6: Scheduling LogGCOp(cdaa3d4df8e6417a8bc97979222734de): free 12017927 bytes of WAL
I20260812 06:19:53.059242 21614 log_reader.cc:385] T cdaa3d4df8e6417a8bc97979222734de: removed 1 log segments from log reader
I20260812 06:19:53.059295 21614 log.cc:1079] T cdaa3d4df8e6417a8bc97979222734de P e042ff8ff313458abebe030f9121dae6: Deleting log segment in path: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585830708-21174-0/minicluster-data/ts-0-root/wals/cdaa3d4df8e6417a8bc97979222734de/wal-000000014 (ops 67-71)
I20260812 06:19:53.062104 21614 maintenance_manager.cc:643] P e042ff8ff313458abebe030f9121dae6: LogGCOp(cdaa3d4df8e6417a8bc97979222734de) complete. Timing: real 0.003s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:19:53.062474 21717 maintenance_manager.cc:419] P e042ff8ff313458abebe030f9121dae6: Scheduling FlushDeltaMemStoresOp(cdaa3d4df8e6417a8bc97979222734de): perf score=2.188937
I20260812 06:19:53.075878 21614 maintenance_manager.cc:643] P e042ff8ff313458abebe030f9121dae6: FlushDeltaMemStoresOp(cdaa3d4df8e6417a8bc97979222734de) complete. Timing: real 0.013s	user 0.006s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5133,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:53.076447 21717 maintenance_manager.cc:419] P e042ff8ff313458abebe030f9121dae6: Scheduling MajorDeltaCompactionOp(cdaa3d4df8e6417a8bc97979222734de): perf score=1.000000
I20260812 06:19:53.325695 21614 maintenance_manager.cc:643] P e042ff8ff313458abebe030f9121dae6: MajorDeltaCompactionOp(cdaa3d4df8e6417a8bc97979222734de) complete. Timing: real 0.249s	user 0.142s	sys 0.099s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020731,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":693,"lbm_read_time_us":17385,"lbm_reads_lt_1ms":774,"lbm_write_time_us":39875,"lbm_writes_lt_1ms":743,"mutex_wait_us":305,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":33280,"thread_start_us":78,"threads_started":1,"update_count":3500}
I20260812 06:19:53.326216 21717 maintenance_manager.cc:419] P e042ff8ff313458abebe030f9121dae6: Scheduling FlushDeltaMemStoresOp(cdaa3d4df8e6417a8bc97979222734de): perf score=18.063937
I20260812 06:19:53.390841 21614 maintenance_manager.cc:643] P e042ff8ff313458abebe030f9121dae6: FlushDeltaMemStoresOp(cdaa3d4df8e6417a8bc97979222734de) complete. Timing: real 0.064s	user 0.030s	sys 0.028s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":25613,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:53.391359 21717 maintenance_manager.cc:419] P e042ff8ff313458abebe030f9121dae6: Scheduling FlushDeltaMemStoresOp(cdaa3d4df8e6417a8bc97979222734de): perf score=2.188937
I20260812 06:19:53.407891 21614 maintenance_manager.cc:643] P e042ff8ff313458abebe030f9121dae6: FlushDeltaMemStoresOp(cdaa3d4df8e6417a8bc97979222734de) complete. Timing: real 0.016s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6240,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:53.408408 21717 maintenance_manager.cc:419] P e042ff8ff313458abebe030f9121dae6: Scheduling MajorDeltaCompactionOp(cdaa3d4df8e6417a8bc97979222734de): perf score=1.000000
I20260812 06:19:53.613277 21614 maintenance_manager.cc:643] P e042ff8ff313458abebe030f9121dae6: MajorDeltaCompactionOp(cdaa3d4df8e6417a8bc97979222734de) complete. Timing: real 0.205s	user 0.139s	sys 0.064s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918099,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":366,"lbm_read_time_us":13247,"lbm_reads_lt_1ms":672,"lbm_write_time_us":33502,"lbm_writes_lt_1ms":643,"mutex_wait_us":68,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":35200,"update_count":3000}
I20260812 06:19:53.614137 21717 maintenance_manager.cc:419] P e042ff8ff313458abebe030f9121dae6: Scheduling FlushDeltaMemStoresOp(cdaa3d4df8e6417a8bc97979222734de): perf score=17.071750
I20260812 06:19:53.681761 21614 maintenance_manager.cc:643] P e042ff8ff313458abebe030f9121dae6: FlushDeltaMemStoresOp(cdaa3d4df8e6417a8bc97979222734de) complete. Timing: real 0.067s	user 0.037s	sys 0.021s Metrics: {"bytes_written":18707249,"delete_count":0,"lbm_write_time_us":28890,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":457,"reinsert_count":0,"update_count":2280}
I20260812 06:19:53.682273 21717 maintenance_manager.cc:419] P e042ff8ff313458abebe030f9121dae6: Scheduling FlushDeltaMemStoresOp(cdaa3d4df8e6417a8bc97979222734de): perf score=4.173312
I20260812 06:19:53.700893 21614 maintenance_manager.cc:643] P e042ff8ff313458abebe030f9121dae6: FlushDeltaMemStoresOp(cdaa3d4df8e6417a8bc97979222734de) complete. Timing: real 0.018s	user 0.011s	sys 0.005s Metrics: {"bytes_written":5907729,"delete_count":0,"lbm_write_time_us":6463,"lbm_writes_lt_1ms":147,"reinsert_count":0,"update_count":720}
I20260812 06:19:53.701421 21717 maintenance_manager.cc:419] P e042ff8ff313458abebe030f9121dae6: Scheduling MajorDeltaCompactionOp(cdaa3d4df8e6417a8bc97979222734de): perf score=1.000000
I20260812 06:19:53.915273 21614 maintenance_manager.cc:643] P e042ff8ff313458abebe030f9121dae6: MajorDeltaCompactionOp(cdaa3d4df8e6417a8bc97979222734de) complete. Timing: real 0.214s	user 0.135s	sys 0.070s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918095,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":995,"lbm_read_time_us":15264,"lbm_reads_lt_1ms":664,"lbm_write_time_us":31891,"lbm_writes_lt_1ms":643,"mutex_wait_us":316,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":41728,"update_count":3000}
I20260812 06:19:53.915956 21717 maintenance_manager.cc:419] P e042ff8ff313458abebe030f9121dae6: Scheduling FlushDeltaMemStoresOp(cdaa3d4df8e6417a8bc97979222734de): perf score=18.063937
I20260812 06:19:53.984490 21614 maintenance_manager.cc:643] P e042ff8ff313458abebe030f9121dae6: FlushDeltaMemStoresOp(cdaa3d4df8e6417a8bc97979222734de) complete. Timing: real 0.068s	user 0.038s	sys 0.012s Metrics: {"bytes_written":20512318,"delete_count":0,"lbm_write_time_us":23855,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:53.985090 21717 maintenance_manager.cc:419] P e042ff8ff313458abebe030f9121dae6: Scheduling FlushDeltaMemStoresOp(cdaa3d4df8e6417a8bc97979222734de): perf score=2.188937
I20260812 06:19:53.997224 21614 maintenance_manager.cc:643] P e042ff8ff313458abebe030f9121dae6: FlushDeltaMemStoresOp(cdaa3d4df8e6417a8bc97979222734de) complete. Timing: real 0.012s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4274,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:53.997838 21717 maintenance_manager.cc:419] P e042ff8ff313458abebe030f9121dae6: Scheduling MajorDeltaCompactionOp(cdaa3d4df8e6417a8bc97979222734de): perf score=1.000000
I20260812 06:19:54.197474 21614 maintenance_manager.cc:643] P e042ff8ff313458abebe030f9121dae6: MajorDeltaCompactionOp(cdaa3d4df8e6417a8bc97979222734de) complete. Timing: real 0.199s	user 0.114s	sys 0.085s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918100,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":981,"lbm_read_time_us":12736,"lbm_reads_lt_1ms":672,"lbm_write_time_us":30648,"lbm_writes_lt_1ms":643,"mutex_wait_us":334,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":19456,"update_count":3000}
I20260812 06:19:54.198041 21717 maintenance_manager.cc:419] P e042ff8ff313458abebe030f9121dae6: Scheduling FlushDeltaMemStoresOp(cdaa3d4df8e6417a8bc97979222734de): perf score=15.087375
I20260812 06:19:54.244956 21614 maintenance_manager.cc:643] P e042ff8ff313458abebe030f9121dae6: FlushDeltaMemStoresOp(cdaa3d4df8e6417a8bc97979222734de) complete. Timing: real 0.047s	user 0.030s	sys 0.013s Metrics: {"bytes_written":16820140,"delete_count":0,"lbm_write_time_us":19930,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:19:54.245602 21717 maintenance_manager.cc:419] P e042ff8ff313458abebe030f9121dae6: Scheduling FlushDeltaMemStoresOp(cdaa3d4df8e6417a8bc97979222734de): perf score=2.188937
I20260812 06:19:54.269701 21614 maintenance_manager.cc:643] P e042ff8ff313458abebe030f9121dae6: FlushDeltaMemStoresOp(cdaa3d4df8e6417a8bc97979222734de) complete. Timing: real 0.024s	user 0.011s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4325,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:54.270243 21717 maintenance_manager.cc:419] P e042ff8ff313458abebe030f9121dae6: Scheduling FlushDeltaMemStoresOp(cdaa3d4df8e6417a8bc97979222734de): perf score=2.188937
I20260812 06:19:54.280651 21614 maintenance_manager.cc:643] P e042ff8ff313458abebe030f9121dae6: FlushDeltaMemStoresOp(cdaa3d4df8e6417a8bc97979222734de) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3792,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:54.281215 21717 maintenance_manager.cc:419] P e042ff8ff313458abebe030f9121dae6: Scheduling MajorDeltaCompactionOp(cdaa3d4df8e6417a8bc97979222734de): perf score=1.000000
I20260812 06:19:54.487097 21614 maintenance_manager.cc:643] P e042ff8ff313458abebe030f9121dae6: MajorDeltaCompactionOp(cdaa3d4df8e6417a8bc97979222734de) complete. Timing: real 0.206s	user 0.149s	sys 0.056s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918199,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":698,"lbm_read_time_us":14830,"lbm_reads_lt_1ms":673,"lbm_write_time_us":34018,"lbm_writes_lt_1ms":643,"mutex_wait_us":345,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":15232,"update_count":3000}
I20260812 06:19:54.487957 21717 maintenance_manager.cc:419] P e042ff8ff313458abebe030f9121dae6: Scheduling FlushDeltaMemStoresOp(cdaa3d4df8e6417a8bc97979222734de): perf score=15.087375
I20260812 06:19:54.537279 21614 maintenance_manager.cc:643] P e042ff8ff313458abebe030f9121dae6: FlushDeltaMemStoresOp(cdaa3d4df8e6417a8bc97979222734de) complete. Timing: real 0.048s	user 0.034s	sys 0.013s Metrics: {"bytes_written":16820143,"delete_count":0,"lbm_write_time_us":20632,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:19:54.537897 21717 maintenance_manager.cc:419] P e042ff8ff313458abebe030f9121dae6: Scheduling FlushDeltaMemStoresOp(cdaa3d4df8e6417a8bc97979222734de): perf score=2.188937
I20260812 06:19:54.549664 21614 maintenance_manager.cc:643] P e042ff8ff313458abebe030f9121dae6: FlushDeltaMemStoresOp(cdaa3d4df8e6417a8bc97979222734de) complete. Timing: real 0.012s	user 0.006s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4386,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:54.550117 21717 maintenance_manager.cc:419] P e042ff8ff313458abebe030f9121dae6: Scheduling FlushMRSOp(cdaa3d4df8e6417a8bc97979222734de): perf score=1.000000
I20260812 06:19:54.575881 21614 maintenance_manager.cc:643] P e042ff8ff313458abebe030f9121dae6: FlushMRSOp(cdaa3d4df8e6417a8bc97979222734de) complete. Timing: real 0.026s	user 0.024s	sys 0.000s Metrics: {"bytes_written":1234479,"cfile_init":1,"dirs.queue_time_us":94,"dirs.run_cpu_time_us":245,"dirs.run_wall_time_us":1245,"drs_written":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1398,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:19:54.576709 21717 maintenance_manager.cc:419] P e042ff8ff313458abebe030f9121dae6: Scheduling LogGCOp(cdaa3d4df8e6417a8bc97979222734de): free 120553392 bytes of WAL
I20260812 06:19:54.577011 21614 log_reader.cc:385] T cdaa3d4df8e6417a8bc97979222734de: removed 12 log segments from log reader
I20260812 06:19:54.577072 21614 log.cc:1079] T cdaa3d4df8e6417a8bc97979222734de P e042ff8ff313458abebe030f9121dae6: Deleting log segment in path: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585830708-21174-0/minicluster-data/ts-0-root/wals/cdaa3d4df8e6417a8bc97979222734de/wal-000000015 (ops 72-76)
I20260812 06:19:54.577116 21614 log.cc:1079] T cdaa3d4df8e6417a8bc97979222734de P e042ff8ff313458abebe030f9121dae6: Deleting log segment in path: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585830708-21174-0/minicluster-data/ts-0-root/wals/cdaa3d4df8e6417a8bc97979222734de/wal-000000016 (ops 77-81)
I20260812 06:19:54.577174 21614 log.cc:1079] T cdaa3d4df8e6417a8bc97979222734de P e042ff8ff313458abebe030f9121dae6: Deleting log segment in path: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585830708-21174-0/minicluster-data/ts-0-root/wals/cdaa3d4df8e6417a8bc97979222734de/wal-000000017 (ops 82-86)
I20260812 06:19:54.577210 21614 log.cc:1079] T cdaa3d4df8e6417a8bc97979222734de P e042ff8ff313458abebe030f9121dae6: Deleting log segment in path: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585830708-21174-0/minicluster-data/ts-0-root/wals/cdaa3d4df8e6417a8bc97979222734de/wal-000000018 (ops 87-91)
I20260812 06:19:54.577248 21614 log.cc:1079] T cdaa3d4df8e6417a8bc97979222734de P e042ff8ff313458abebe030f9121dae6: Deleting log segment in path: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585830708-21174-0/minicluster-data/ts-0-root/wals/cdaa3d4df8e6417a8bc97979222734de/wal-000000019 (ops 92-96)
I20260812 06:19:54.577282 21614 log.cc:1079] T cdaa3d4df8e6417a8bc97979222734de P e042ff8ff313458abebe030f9121dae6: Deleting log segment in path: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585830708-21174-0/minicluster-data/ts-0-root/wals/cdaa3d4df8e6417a8bc97979222734de/wal-000000020 (ops 97-100)
I20260812 06:19:54.577313 21614 log.cc:1079] T cdaa3d4df8e6417a8bc97979222734de P e042ff8ff313458abebe030f9121dae6: Deleting log segment in path: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585830708-21174-0/minicluster-data/ts-0-root/wals/cdaa3d4df8e6417a8bc97979222734de/wal-000000021 (ops 101-105)
I20260812 06:19:54.577346 21614 log.cc:1079] T cdaa3d4df8e6417a8bc97979222734de P e042ff8ff313458abebe030f9121dae6: Deleting log segment in path: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585830708-21174-0/minicluster-data/ts-0-root/wals/cdaa3d4df8e6417a8bc97979222734de/wal-000000022 (ops 106-110)
I20260812 06:19:54.577378 21614 log.cc:1079] T cdaa3d4df8e6417a8bc97979222734de P e042ff8ff313458abebe030f9121dae6: Deleting log segment in path: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585830708-21174-0/minicluster-data/ts-0-root/wals/cdaa3d4df8e6417a8bc97979222734de/wal-000000023 (ops 111-115)
I20260812 06:19:54.577410 21614 log.cc:1079] T cdaa3d4df8e6417a8bc97979222734de P e042ff8ff313458abebe030f9121dae6: Deleting log segment in path: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585830708-21174-0/minicluster-data/ts-0-root/wals/cdaa3d4df8e6417a8bc97979222734de/wal-000000024 (ops 116-120)
I20260812 06:19:54.577442 21614 log.cc:1079] T cdaa3d4df8e6417a8bc97979222734de P e042ff8ff313458abebe030f9121dae6: Deleting log segment in path: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585830708-21174-0/minicluster-data/ts-0-root/wals/cdaa3d4df8e6417a8bc97979222734de/wal-000000025 (ops 121-124)
I20260812 06:19:54.577473 21614 log.cc:1079] T cdaa3d4df8e6417a8bc97979222734de P e042ff8ff313458abebe030f9121dae6: Deleting log segment in path: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585830708-21174-0/minicluster-data/ts-0-root/wals/cdaa3d4df8e6417a8bc97979222734de/wal-000000026 (ops 125-129)
I20260812 06:19:54.600587 21614 maintenance_manager.cc:643] P e042ff8ff313458abebe030f9121dae6: LogGCOp(cdaa3d4df8e6417a8bc97979222734de) complete. Timing: real 0.024s	user 0.002s	sys 0.019s Metrics: {}
I20260812 06:19:54.601265 21717 maintenance_manager.cc:419] P e042ff8ff313458abebe030f9121dae6: Scheduling FlushDeltaMemStoresOp(cdaa3d4df8e6417a8bc97979222734de): perf score=3.181125
I20260812 06:19:54.614148 21614 maintenance_manager.cc:643] P e042ff8ff313458abebe030f9121dae6: FlushDeltaMemStoresOp(cdaa3d4df8e6417a8bc97979222734de) complete. Timing: real 0.013s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4964169,"delete_count":0,"lbm_write_time_us":4725,"lbm_writes_lt_1ms":124,"reinsert_count":0,"update_count":605}
I20260812 06:19:54.614662 21717 maintenance_manager.cc:419] P e042ff8ff313458abebe030f9121dae6: Scheduling FlushDeltaMemStoresOp(cdaa3d4df8e6417a8bc97979222734de): perf score=2.188937
I20260812 06:19:54.627341 21614 maintenance_manager.cc:643] P e042ff8ff313458abebe030f9121dae6: FlushDeltaMemStoresOp(cdaa3d4df8e6417a8bc97979222734de) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":3241130,"delete_count":0,"lbm_write_time_us":4327,"lbm_writes_lt_1ms":82,"reinsert_count":0,"update_count":395}
I20260812 06:19:54.627966 21717 maintenance_manager.cc:419] P e042ff8ff313458abebe030f9121dae6: Scheduling MajorDeltaCompactionOp(cdaa3d4df8e6417a8bc97979222734de): perf score=1.000000
I20260812 06:19:54.853876 21614 maintenance_manager.cc:643] P e042ff8ff313458abebe030f9121dae6: MajorDeltaCompactionOp(cdaa3d4df8e6417a8bc97979222734de) complete. Timing: real 0.226s	user 0.135s	sys 0.079s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020714,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":691,"lbm_read_time_us":15550,"lbm_reads_lt_1ms":774,"lbm_write_time_us":38552,"lbm_writes_lt_1ms":743,"mutex_wait_us":373,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":15744,"thread_start_us":83,"threads_started":1,"update_count":3500}
I20260812 06:19:54.854481 21717 maintenance_manager.cc:419] P e042ff8ff313458abebe030f9121dae6: Scheduling FlushDeltaMemStoresOp(cdaa3d4df8e6417a8bc97979222734de): perf score=18.063937
I20260812 06:19:54.933378 21614 maintenance_manager.cc:643] P e042ff8ff313458abebe030f9121dae6: FlushDeltaMemStoresOp(cdaa3d4df8e6417a8bc97979222734de) complete. Timing: real 0.079s	user 0.026s	sys 0.029s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":48099,"lbm_writes_10-100_ms":1,"lbm_writes_lt_1ms":502,"reinsert_count":0,"update_count":2500}
I20260812 06:19:54.934010 21717 maintenance_manager.cc:419] P e042ff8ff313458abebe030f9121dae6: Scheduling UndoDeltaBlockGCOp(cdaa3d4df8e6417a8bc97979222734de): 473 bytes on disk
I20260812 06:19:54.934495 21614 maintenance_manager.cc:643] P e042ff8ff313458abebe030f9121dae6: UndoDeltaBlockGCOp(cdaa3d4df8e6417a8bc97979222734de) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4}
I20260812 06:19:54.935058 21717 maintenance_manager.cc:419] P e042ff8ff313458abebe030f9121dae6: Scheduling FlushDeltaMemStoresOp(cdaa3d4df8e6417a8bc97979222734de): perf score=2.188937
I20260812 06:19:54.947258 21614 maintenance_manager.cc:643] P e042ff8ff313458abebe030f9121dae6: FlushDeltaMemStoresOp(cdaa3d4df8e6417a8bc97979222734de) complete. Timing: real 0.012s	user 0.008s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4572,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:54.947778 21717 maintenance_manager.cc:419] P e042ff8ff313458abebe030f9121dae6: Scheduling MajorDeltaCompactionOp(cdaa3d4df8e6417a8bc97979222734de): perf score=1.000000
I20260812 06:19:55.107897 21614 maintenance_manager.cc:643] P e042ff8ff313458abebe030f9121dae6: MajorDeltaCompactionOp(cdaa3d4df8e6417a8bc97979222734de) complete. Timing: real 0.160s	user 0.129s	sys 0.030s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918098,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":268,"lbm_read_time_us":12490,"lbm_reads_lt_1ms":672,"lbm_write_time_us":31769,"lbm_writes_lt_1ms":643,"mutex_wait_us":47,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":4736,"update_count":3000}
I20260812 06:19:55.108505 21717 maintenance_manager.cc:419] P e042ff8ff313458abebe030f9121dae6: Scheduling FlushDeltaMemStoresOp(cdaa3d4df8e6417a8bc97979222734de): perf score=14.095187
I20260812 06:19:55.158039 21614 maintenance_manager.cc:643] P e042ff8ff313458abebe030f9121dae6: FlushDeltaMemStoresOp(cdaa3d4df8e6417a8bc97979222734de) complete. Timing: real 0.049s	user 0.027s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19365,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:55.158677 21717 maintenance_manager.cc:419] P e042ff8ff313458abebe030f9121dae6: Scheduling FlushDeltaMemStoresOp(cdaa3d4df8e6417a8bc97979222734de): perf score=2.188937
I20260812 06:19:55.169780 21614 maintenance_manager.cc:643] P e042ff8ff313458abebe030f9121dae6: FlushDeltaMemStoresOp(cdaa3d4df8e6417a8bc97979222734de) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3988,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:55.170431 21717 maintenance_manager.cc:419] P e042ff8ff313458abebe030f9121dae6: Scheduling MajorDeltaCompactionOp(cdaa3d4df8e6417a8bc97979222734de): perf score=1.000000
I20260812 06:19:55.331614 21614 maintenance_manager.cc:643] P e042ff8ff313458abebe030f9121dae6: MajorDeltaCompactionOp(cdaa3d4df8e6417a8bc97979222734de) complete. Timing: real 0.161s	user 0.115s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":142,"lbm_read_time_us":12426,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31194,"lbm_writes_lt_1ms":543,"mutex_wait_us":83,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6656,"update_count":2500}
I20260812 06:19:55.332226 21717 maintenance_manager.cc:419] P e042ff8ff313458abebe030f9121dae6: Scheduling FlushDeltaMemStoresOp(cdaa3d4df8e6417a8bc97979222734de): perf score=12.110812
I20260812 06:19:55.376616 21614 maintenance_manager.cc:643] P e042ff8ff313458abebe030f9121dae6: FlushDeltaMemStoresOp(cdaa3d4df8e6417a8bc97979222734de) complete. Timing: real 0.044s	user 0.017s	sys 0.024s Metrics: {"bytes_written":14030495,"delete_count":0,"lbm_write_time_us":18571,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":344,"reinsert_count":0,"update_count":1710}
I20260812 06:19:55.377259 21717 maintenance_manager.cc:419] P e042ff8ff313458abebe030f9121dae6: Scheduling FlushDeltaMemStoresOp(cdaa3d4df8e6417a8bc97979222734de): perf score=1.196750
I20260812 06:19:55.393239 21614 maintenance_manager.cc:643] P e042ff8ff313458abebe030f9121dae6: FlushDeltaMemStoresOp(cdaa3d4df8e6417a8bc97979222734de) complete. Timing: real 0.016s	user 0.004s	sys 0.005s Metrics: {"bytes_written":2379604,"delete_count":0,"lbm_write_time_us":2915,"lbm_writes_lt_1ms":61,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":290}
I20260812 06:19:55.393733 21717 maintenance_manager.cc:419] P e042ff8ff313458abebe030f9121dae6: Scheduling FlushDeltaMemStoresOp(cdaa3d4df8e6417a8bc97979222734de): perf score=2.188937
I20260812 06:19:55.404191 21614 maintenance_manager.cc:643] P e042ff8ff313458abebe030f9121dae6: FlushDeltaMemStoresOp(cdaa3d4df8e6417a8bc97979222734de) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3728,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:55.404711 21717 maintenance_manager.cc:419] P e042ff8ff313458abebe030f9121dae6: Scheduling MajorDeltaCompactionOp(cdaa3d4df8e6417a8bc97979222734de): perf score=1.000000
I20260812 06:19:55.578011 21614 maintenance_manager.cc:643] P e042ff8ff313458abebe030f9121dae6: MajorDeltaCompactionOp(cdaa3d4df8e6417a8bc97979222734de) complete. Timing: real 0.173s	user 0.134s	sys 0.036s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815753,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":560,"lbm_read_time_us":12932,"lbm_reads_lt_1ms":573,"lbm_write_time_us":28231,"lbm_writes_lt_1ms":543,"mutex_wait_us":290,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":19072,"update_count":2500}
I20260812 06:19:55.578617 21717 maintenance_manager.cc:419] P e042ff8ff313458abebe030f9121dae6: Scheduling FlushDeltaMemStoresOp(cdaa3d4df8e6417a8bc97979222734de): perf score=14.095187
I20260812 06:19:55.632673 21614 maintenance_manager.cc:643] P e042ff8ff313458abebe030f9121dae6: FlushDeltaMemStoresOp(cdaa3d4df8e6417a8bc97979222734de) complete. Timing: real 0.054s	user 0.029s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20360,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:55.633270 21717 maintenance_manager.cc:419] P e042ff8ff313458abebe030f9121dae6: Scheduling FlushDeltaMemStoresOp(cdaa3d4df8e6417a8bc97979222734de): perf score=2.188937
I20260812 06:19:55.643616 21614 maintenance_manager.cc:643] P e042ff8ff313458abebe030f9121dae6: FlushDeltaMemStoresOp(cdaa3d4df8e6417a8bc97979222734de) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3786,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:55.644114 21717 maintenance_manager.cc:419] P e042ff8ff313458abebe030f9121dae6: Scheduling MajorDeltaCompactionOp(cdaa3d4df8e6417a8bc97979222734de): perf score=1.000000
I20260812 06:19:55.810322 21614 maintenance_manager.cc:643] P e042ff8ff313458abebe030f9121dae6: MajorDeltaCompactionOp(cdaa3d4df8e6417a8bc97979222734de) complete. Timing: real 0.166s	user 0.134s	sys 0.032s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":184,"lbm_read_time_us":11773,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26967,"lbm_writes_lt_1ms":543,"mutex_wait_us":39,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9728,"update_count":2500}
I20260812 06:19:55.811058 21717 maintenance_manager.cc:419] P e042ff8ff313458abebe030f9121dae6: Scheduling FlushDeltaMemStoresOp(cdaa3d4df8e6417a8bc97979222734de): perf score=14.095187
I20260812 06:19:55.863998 21614 maintenance_manager.cc:643] P e042ff8ff313458abebe030f9121dae6: FlushDeltaMemStoresOp(cdaa3d4df8e6417a8bc97979222734de) complete. Timing: real 0.053s	user 0.023s	sys 0.027s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":20135,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:55.864720 21717 maintenance_manager.cc:419] P e042ff8ff313458abebe030f9121dae6: Scheduling FlushDeltaMemStoresOp(cdaa3d4df8e6417a8bc97979222734de): perf score=2.188937
I20260812 06:19:55.875254 21614 maintenance_manager.cc:643] P e042ff8ff313458abebe030f9121dae6: FlushDeltaMemStoresOp(cdaa3d4df8e6417a8bc97979222734de) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3831,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:55.875731 21717 maintenance_manager.cc:419] P e042ff8ff313458abebe030f9121dae6: Scheduling FlushMRSOp(cdaa3d4df8e6417a8bc97979222734de): perf score=1.000000
I20260812 06:19:55.916117 21614 maintenance_manager.cc:643] P e042ff8ff313458abebe030f9121dae6: FlushMRSOp(cdaa3d4df8e6417a8bc97979222734de) complete. Timing: real 0.040s	user 0.031s	sys 0.000s Metrics: {"bytes_written":1152510,"cfile_init":1,"dirs.queue_time_us":79,"dirs.run_cpu_time_us":209,"dirs.run_wall_time_us":1134,"drs_written":1,"lbm_read_time_us":62,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1931,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28,"spinlock_wait_cycles":4992}
I20260812 06:19:55.916862 21717 maintenance_manager.cc:419] P e042ff8ff313458abebe030f9121dae6: Scheduling LogGCOp(cdaa3d4df8e6417a8bc97979222734de): free 112239517 bytes of WAL
I20260812 06:19:55.917089 21614 log_reader.cc:385] T cdaa3d4df8e6417a8bc97979222734de: removed 11 log segments from log reader
I20260812 06:19:55.917135 21614 log.cc:1079] T cdaa3d4df8e6417a8bc97979222734de P e042ff8ff313458abebe030f9121dae6: Deleting log segment in path: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585830708-21174-0/minicluster-data/ts-0-root/wals/cdaa3d4df8e6417a8bc97979222734de/wal-000000027 (ops 130-134)
I20260812 06:19:55.917192 21614 log.cc:1079] T cdaa3d4df8e6417a8bc97979222734de P e042ff8ff313458abebe030f9121dae6: Deleting log segment in path: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585830708-21174-0/minicluster-data/ts-0-root/wals/cdaa3d4df8e6417a8bc97979222734de/wal-000000028 (ops 135-138)
I20260812 06:19:55.917227 21614 log.cc:1079] T cdaa3d4df8e6417a8bc97979222734de P e042ff8ff313458abebe030f9121dae6: Deleting log segment in path: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585830708-21174-0/minicluster-data/ts-0-root/wals/cdaa3d4df8e6417a8bc97979222734de/wal-000000029 (ops 139-143)
I20260812 06:19:55.917249 21614 log.cc:1079] T cdaa3d4df8e6417a8bc97979222734de P e042ff8ff313458abebe030f9121dae6: Deleting log segment in path: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585830708-21174-0/minicluster-data/ts-0-root/wals/cdaa3d4df8e6417a8bc97979222734de/wal-000000030 (ops 144-148)
I20260812 06:19:55.917282 21614 log.cc:1079] T cdaa3d4df8e6417a8bc97979222734de P e042ff8ff313458abebe030f9121dae6: Deleting log segment in path: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585830708-21174-0/minicluster-data/ts-0-root/wals/cdaa3d4df8e6417a8bc97979222734de/wal-000000031 (ops 149-153)
I20260812 06:19:55.917313 21614 log.cc:1079] T cdaa3d4df8e6417a8bc97979222734de P e042ff8ff313458abebe030f9121dae6: Deleting log segment in path: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585830708-21174-0/minicluster-data/ts-0-root/wals/cdaa3d4df8e6417a8bc97979222734de/wal-000000032 (ops 154-158)
I20260812 06:19:55.917343 21614 log.cc:1079] T cdaa3d4df8e6417a8bc97979222734de P e042ff8ff313458abebe030f9121dae6: Deleting log segment in path: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585830708-21174-0/minicluster-data/ts-0-root/wals/cdaa3d4df8e6417a8bc97979222734de/wal-000000033 (ops 159-163)
I20260812 06:19:55.917374 21614 log.cc:1079] T cdaa3d4df8e6417a8bc97979222734de P e042ff8ff313458abebe030f9121dae6: Deleting log segment in path: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585830708-21174-0/minicluster-data/ts-0-root/wals/cdaa3d4df8e6417a8bc97979222734de/wal-000000034 (ops 164-168)
I20260812 06:19:55.917404 21614 log.cc:1079] T cdaa3d4df8e6417a8bc97979222734de P e042ff8ff313458abebe030f9121dae6: Deleting log segment in path: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585830708-21174-0/minicluster-data/ts-0-root/wals/cdaa3d4df8e6417a8bc97979222734de/wal-000000035 (ops 169-173)
I20260812 06:19:55.917434 21614 log.cc:1079] T cdaa3d4df8e6417a8bc97979222734de P e042ff8ff313458abebe030f9121dae6: Deleting log segment in path: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585830708-21174-0/minicluster-data/ts-0-root/wals/cdaa3d4df8e6417a8bc97979222734de/wal-000000036 (ops 174-178)
I20260812 06:19:55.917464 21614 log.cc:1079] T cdaa3d4df8e6417a8bc97979222734de P e042ff8ff313458abebe030f9121dae6: Deleting log segment in path: /tmp/dist-test-taska1BGk_/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515585830708-21174-0/minicluster-data/ts-0-root/wals/cdaa3d4df8e6417a8bc97979222734de/wal-000000037 (ops 179-183)
I20260812 06:19:55.936765 21614 maintenance_manager.cc:643] P e042ff8ff313458abebe030f9121dae6: LogGCOp(cdaa3d4df8e6417a8bc97979222734de) complete. Timing: real 0.020s	user 0.002s	sys 0.015s Metrics: {}
I20260812 06:19:55.937400 21717 maintenance_manager.cc:419] P e042ff8ff313458abebe030f9121dae6: Scheduling FlushDeltaMemStoresOp(cdaa3d4df8e6417a8bc97979222734de): perf score=2.188937
I20260812 06:19:55.960873 21614 maintenance_manager.cc:643] P e042ff8ff313458abebe030f9121dae6: FlushDeltaMemStoresOp(cdaa3d4df8e6417a8bc97979222734de) complete. Timing: real 0.023s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5638,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:55.961467 21717 maintenance_manager.cc:419] P e042ff8ff313458abebe030f9121dae6: Scheduling FlushDeltaMemStoresOp(cdaa3d4df8e6417a8bc97979222734de): perf score=2.188937
I20260812 06:19:55.972062 21614 maintenance_manager.cc:643] P e042ff8ff313458abebe030f9121dae6: FlushDeltaMemStoresOp(cdaa3d4df8e6417a8bc97979222734de) complete. Timing: real 0.010s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3850,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:55.972785 21717 maintenance_manager.cc:419] P e042ff8ff313458abebe030f9121dae6: Scheduling MajorDeltaCompactionOp(cdaa3d4df8e6417a8bc97979222734de): perf score=1.000000
I20260812 06:19:56.201853 21614 maintenance_manager.cc:643] P e042ff8ff313458abebe030f9121dae6: MajorDeltaCompactionOp(cdaa3d4df8e6417a8bc97979222734de) complete. Timing: real 0.229s	user 0.169s	sys 0.052s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020743,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":812,"lbm_read_time_us":15828,"lbm_reads_lt_1ms":774,"lbm_write_time_us":39110,"lbm_writes_lt_1ms":743,"mutex_wait_us":52,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":723584,"thread_start_us":75,"threads_started":1,"update_count":3500}
I20260812 06:19:56.202477 21717 maintenance_manager.cc:419] P e042ff8ff313458abebe030f9121dae6: Scheduling UndoDeltaBlockGCOp(cdaa3d4df8e6417a8bc97979222734de): 447 bytes on disk
I20260812 06:19:56.202936 21614 maintenance_manager.cc:643] P e042ff8ff313458abebe030f9121dae6: UndoDeltaBlockGCOp(cdaa3d4df8e6417a8bc97979222734de) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4}
I20260812 06:19:56.203544 21717 maintenance_manager.cc:419] P e042ff8ff313458abebe030f9121dae6: Scheduling FlushDeltaMemStoresOp(cdaa3d4df8e6417a8bc97979222734de): perf score=18.063937
I20260812 06:19:56.255139 21174 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.830s	user 1.706s	sys 0.142s
I20260812 06:19:56.258773 21614 maintenance_manager.cc:643] P e042ff8ff313458abebe030f9121dae6: FlushDeltaMemStoresOp(cdaa3d4df8e6417a8bc97979222734de) complete. Timing: real 0.055s	user 0.030s	sys 0.016s Metrics: {"bytes_written":20512314,"delete_count":0,"lbm_write_time_us":20649,"lbm_writes_lt_1ms":503,"reinsert_count":0,"spinlock_wait_cycles":2816,"update_count":2500}
I20260812 06:19:56.259366 21717 maintenance_manager.cc:419] P e042ff8ff313458abebe030f9121dae6: Scheduling FlushDeltaMemStoresOp(cdaa3d4df8e6417a8bc97979222734de): perf score=2.188937
I20260812 06:19:56.275492 21614 maintenance_manager.cc:643] P e042ff8ff313458abebe030f9121dae6: FlushDeltaMemStoresOp(cdaa3d4df8e6417a8bc97979222734de) complete. Timing: real 0.016s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6205,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:56.276010 21717 maintenance_manager.cc:419] P e042ff8ff313458abebe030f9121dae6: Scheduling MajorDeltaCompactionOp(cdaa3d4df8e6417a8bc97979222734de): perf score=1.000000
I20260812 06:19:56.321987 21174 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.066s	user 0.002s	sys 0.000s
I20260812 06:19:56.322510 21174 tablet_server.cc:179] TabletServer@127.20.173.129:0 shutting down...
I20260812 06:19:56.424723 21614 maintenance_manager.cc:643] P e042ff8ff313458abebe030f9121dae6: MajorDeltaCompactionOp(cdaa3d4df8e6417a8bc97979222734de) complete. Timing: real 0.149s	user 0.128s	sys 0.020s Metrics: {"cfile_cache_hit":451,"cfile_cache_hit_bytes":18461630,"cfile_cache_miss":181,"cfile_cache_miss_bytes":10456465,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":784,"lbm_read_time_us":5658,"lbm_reads_lt_1ms":213,"lbm_write_time_us":29303,"lbm_writes_lt_1ms":643,"mutex_wait_us":329,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":18816,"update_count":3000}
I20260812 06:19:56.425403 21174 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:56.425706 21174 tablet_replica.cc:333] T cdaa3d4df8e6417a8bc97979222734de P e042ff8ff313458abebe030f9121dae6: stopping tablet replica
I20260812 06:19:56.425853 21174 raft_consensus.cc:2243] T cdaa3d4df8e6417a8bc97979222734de P e042ff8ff313458abebe030f9121dae6 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:56.426023 21174 raft_consensus.cc:2272] T cdaa3d4df8e6417a8bc97979222734de P e042ff8ff313458abebe030f9121dae6 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:56.429943 21174 tablet_server.cc:196] TabletServer@127.20.173.129:0 shutdown complete.
I20260812 06:19:56.477633 21174 master.cc:562] Master@127.20.173.190:39817 shutting down...
I20260812 06:19:56.480620 21174 raft_consensus.cc:2243] T 00000000000000000000000000000000 P d26d2e682fd941159a033d25af1477d1 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:56.480819 21174 raft_consensus.cc:2272] T 00000000000000000000000000000000 P d26d2e682fd941159a033d25af1477d1 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:56.480896 21174 tablet_replica.cc:333] T 00000000000000000000000000000000 P d26d2e682fd941159a033d25af1477d1: stopping tablet replica
I20260812 06:19:56.493655 21174 master.cc:584] Master@127.20.173.190:39817 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5332 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10730 ms total)

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