[==========] 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:17:55.060866 27629 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.26.251.126:46213
I20260812 06:17:55.061872 27629 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:17:55.062467 27629 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:55.068552 27641 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:55.068604 27629 server_base.cc:1061] running on GCE node
W20260812 06:17:55.068557 27636 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:17:55.068850 27635 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:17:55.069370 27629 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:55.069458 27629 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:17:55.069481 27629 hybrid_clock.cc:648] HybridClock initialized: now 1786515475069480 us; error 0 us; skew 500 ppm
I20260812 06:17:55.071097 27629 webserver.cc:533] Webserver started at http://127.26.251.126:41463/ using document root <none> and password file <none>
I20260812 06:17:55.071564 27629 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:55.071620 27629 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:55.071803 27629 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:55.073410 27629 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475050180-27629-0/minicluster-data/master-0-root/instance:
uuid: "5d311e4f02bd4bd7aa8d86a39199c040"
format_stamp: "Formatted at 2026-08-12 06:17:55 on dist-test-slave-t3q3"
I20260812 06:17:55.076674 27629 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.001s	sys 0.003s
I20260812 06:17:55.078650 27648 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:17:55.079722 27629 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:55.079843 27629 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475050180-27629-0/minicluster-data/master-0-root
uuid: "5d311e4f02bd4bd7aa8d86a39199c040"
format_stamp: "Formatted at 2026-08-12 06:17:55 on dist-test-slave-t3q3"
I20260812 06:17:55.079947 27629 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475050180-27629-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475050180-27629-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475050180-27629-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:17:55.089295 27629 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:55.089917 27629 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:17:55.090096 27629 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:55.098039 27735 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.26.251.126:46213 every 8 connection(s)
I20260812 06:17:55.098052 27629 rpc_server.cc:307] RPC server started. Bound to: 127.26.251.126:46213
I20260812 06:17:55.100466 27741 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:17:55.105970 27741 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 5d311e4f02bd4bd7aa8d86a39199c040: Bootstrap starting.
I20260812 06:17:55.108346 27741 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 5d311e4f02bd4bd7aa8d86a39199c040: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:55.109269 27741 log.cc:826] T 00000000000000000000000000000000 P 5d311e4f02bd4bd7aa8d86a39199c040: Log is configured to *not* fsync() on all Append() calls
I20260812 06:17:55.110960 27741 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 5d311e4f02bd4bd7aa8d86a39199c040: No bootstrap required, opened a new log
I20260812 06:17:55.113828 27741 raft_consensus.cc:359] T 00000000000000000000000000000000 P 5d311e4f02bd4bd7aa8d86a39199c040 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5d311e4f02bd4bd7aa8d86a39199c040" member_type: VOTER }
I20260812 06:17:55.113996 27741 raft_consensus.cc:385] T 00000000000000000000000000000000 P 5d311e4f02bd4bd7aa8d86a39199c040 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:55.114125 27741 raft_consensus.cc:740] T 00000000000000000000000000000000 P 5d311e4f02bd4bd7aa8d86a39199c040 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 5d311e4f02bd4bd7aa8d86a39199c040, State: Initialized, Role: FOLLOWER
I20260812 06:17:55.114748 27741 consensus_queue.cc:260] T 00000000000000000000000000000000 P 5d311e4f02bd4bd7aa8d86a39199c040 [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: "5d311e4f02bd4bd7aa8d86a39199c040" member_type: VOTER }
I20260812 06:17:55.114918 27741 raft_consensus.cc:399] T 00000000000000000000000000000000 P 5d311e4f02bd4bd7aa8d86a39199c040 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:55.115015 27741 raft_consensus.cc:493] T 00000000000000000000000000000000 P 5d311e4f02bd4bd7aa8d86a39199c040 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:55.115173 27741 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 5d311e4f02bd4bd7aa8d86a39199c040 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:55.115978 27741 raft_consensus.cc:515] T 00000000000000000000000000000000 P 5d311e4f02bd4bd7aa8d86a39199c040 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5d311e4f02bd4bd7aa8d86a39199c040" member_type: VOTER }
I20260812 06:17:55.116456 27741 leader_election.cc:304] T 00000000000000000000000000000000 P 5d311e4f02bd4bd7aa8d86a39199c040 [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: 5d311e4f02bd4bd7aa8d86a39199c040; no voters: 
I20260812 06:17:55.116838 27741 leader_election.cc:290] T 00000000000000000000000000000000 P 5d311e4f02bd4bd7aa8d86a39199c040 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:55.117043 27746 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 5d311e4f02bd4bd7aa8d86a39199c040 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:55.117332 27746 raft_consensus.cc:697] T 00000000000000000000000000000000 P 5d311e4f02bd4bd7aa8d86a39199c040 [term 1 LEADER]: Becoming Leader. State: Replica: 5d311e4f02bd4bd7aa8d86a39199c040, State: Running, Role: LEADER
I20260812 06:17:55.117800 27746 consensus_queue.cc:237] T 00000000000000000000000000000000 P 5d311e4f02bd4bd7aa8d86a39199c040 [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: "5d311e4f02bd4bd7aa8d86a39199c040" member_type: VOTER }
I20260812 06:17:55.117974 27741 sys_catalog.cc:565] T 00000000000000000000000000000000 P 5d311e4f02bd4bd7aa8d86a39199c040 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:55.119675 27748 sys_catalog.cc:455] T 00000000000000000000000000000000 P 5d311e4f02bd4bd7aa8d86a39199c040 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 5d311e4f02bd4bd7aa8d86a39199c040. Latest consensus state: current_term: 1 leader_uuid: "5d311e4f02bd4bd7aa8d86a39199c040" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5d311e4f02bd4bd7aa8d86a39199c040" member_type: VOTER } }
I20260812 06:17:55.119714 27747 sys_catalog.cc:455] T 00000000000000000000000000000000 P 5d311e4f02bd4bd7aa8d86a39199c040 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "5d311e4f02bd4bd7aa8d86a39199c040" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5d311e4f02bd4bd7aa8d86a39199c040" member_type: VOTER } }
I20260812 06:17:55.119805 27748 sys_catalog.cc:458] T 00000000000000000000000000000000 P 5d311e4f02bd4bd7aa8d86a39199c040 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:55.119813 27747 sys_catalog.cc:458] T 00000000000000000000000000000000 P 5d311e4f02bd4bd7aa8d86a39199c040 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:55.120271 27774 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:55.120498 27629 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:55.122512 27774 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:55.126806 27774 catalog_manager.cc:1383] Generated new cluster ID: aa8f3a9a9b474ba0a1b2aeffafb0a4f4
I20260812 06:17:55.126871 27774 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:55.144886 27774 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:55.145825 27774 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:55.155786 27774 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 5d311e4f02bd4bd7aa8d86a39199c040: Generated new TSK 0
I20260812 06:17:55.156479 27774 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:55.185364 27629 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:55.188210 27794 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:17:55.188280 27789 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:17:55.188345 27786 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:17:55.188920 27629 server_base.cc:1061] running on GCE node
I20260812 06:17:55.189160 27629 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:55.189217 27629 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:17:55.189235 27629 hybrid_clock.cc:648] HybridClock initialized: now 1786515475189235 us; error 0 us; skew 500 ppm
I20260812 06:17:55.190254 27629 webserver.cc:533] Webserver started at http://127.26.251.65:37065/ using document root <none> and password file <none>
I20260812 06:17:55.190441 27629 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:55.190500 27629 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:55.190584 27629 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:55.191035 27629 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475050180-27629-0/minicluster-data/ts-0-root/instance:
uuid: "ce19d736c8a4451fbfda411024669fbb"
format_stamp: "Formatted at 2026-08-12 06:17:55 on dist-test-slave-t3q3"
I20260812 06:17:55.192777 27629 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:17:55.193849 27801 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:17:55.194103 27629 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:55.194182 27629 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475050180-27629-0/minicluster-data/ts-0-root
uuid: "ce19d736c8a4451fbfda411024669fbb"
format_stamp: "Formatted at 2026-08-12 06:17:55 on dist-test-slave-t3q3"
I20260812 06:17:55.194275 27629 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475050180-27629-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475050180-27629-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475050180-27629-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:17:55.202785 27629 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:55.203230 27629 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:55.203727 27629 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:55.204718 27629 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:55.204774 27629 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:55.204841 27629 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:55.204883 27629 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:55.212175 27629 rpc_server.cc:307] RPC server started. Bound to: 127.26.251.65:45841
I20260812 06:17:55.212203 27913 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.26.251.65:45841 every 8 connection(s)
I20260812 06:17:55.226011 27915 heartbeater.cc:344] Connected to a master server at 127.26.251.126:46213
I20260812 06:17:55.226332 27915 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:55.226837 27915 heartbeater.cc:507] Master 127.26.251.126:46213 requested a full tablet report, sending...
I20260812 06:17:55.228369 27678 ts_manager.cc:194] Registered new tserver with Master: ce19d736c8a4451fbfda411024669fbb (127.26.251.65:45841)
I20260812 06:17:55.228556 27629 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.015699984s
I20260812 06:17:55.229907 27678 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:55044
I20260812 06:17:55.238530 27678 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:55056:
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:17:55.254189 27850 tablet_service.cc:1511] Processing CreateTablet for tablet 4cce3831782e468d9bdad5e14d9b457b (DEFAULT_TABLE table=heavy-update-compaction-test [id=5ad8649f5cd44e629d6c5da0db78714a]), partition=
I20260812 06:17:55.254667 27850 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 4cce3831782e468d9bdad5e14d9b457b. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:55.257153 27935 tablet_bootstrap.cc:492] T 4cce3831782e468d9bdad5e14d9b457b P ce19d736c8a4451fbfda411024669fbb: Bootstrap starting.
I20260812 06:17:55.258173 27935 tablet_bootstrap.cc:654] T 4cce3831782e468d9bdad5e14d9b457b P ce19d736c8a4451fbfda411024669fbb: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:55.259341 27935 tablet_bootstrap.cc:492] T 4cce3831782e468d9bdad5e14d9b457b P ce19d736c8a4451fbfda411024669fbb: No bootstrap required, opened a new log
I20260812 06:17:55.259431 27935 ts_tablet_manager.cc:1403] T 4cce3831782e468d9bdad5e14d9b457b P ce19d736c8a4451fbfda411024669fbb: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:55.260249 27935 raft_consensus.cc:359] T 4cce3831782e468d9bdad5e14d9b457b P ce19d736c8a4451fbfda411024669fbb [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ce19d736c8a4451fbfda411024669fbb" member_type: VOTER last_known_addr { host: "127.26.251.65" port: 45841 } }
I20260812 06:17:55.260354 27935 raft_consensus.cc:385] T 4cce3831782e468d9bdad5e14d9b457b P ce19d736c8a4451fbfda411024669fbb [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:55.260377 27935 raft_consensus.cc:740] T 4cce3831782e468d9bdad5e14d9b457b P ce19d736c8a4451fbfda411024669fbb [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: ce19d736c8a4451fbfda411024669fbb, State: Initialized, Role: FOLLOWER
I20260812 06:17:55.260550 27935 consensus_queue.cc:260] T 4cce3831782e468d9bdad5e14d9b457b P ce19d736c8a4451fbfda411024669fbb [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: "ce19d736c8a4451fbfda411024669fbb" member_type: VOTER last_known_addr { host: "127.26.251.65" port: 45841 } }
I20260812 06:17:55.260663 27935 raft_consensus.cc:399] T 4cce3831782e468d9bdad5e14d9b457b P ce19d736c8a4451fbfda411024669fbb [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:55.260723 27935 raft_consensus.cc:493] T 4cce3831782e468d9bdad5e14d9b457b P ce19d736c8a4451fbfda411024669fbb [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:55.260787 27935 raft_consensus.cc:3060] T 4cce3831782e468d9bdad5e14d9b457b P ce19d736c8a4451fbfda411024669fbb [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:55.261740 27935 raft_consensus.cc:515] T 4cce3831782e468d9bdad5e14d9b457b P ce19d736c8a4451fbfda411024669fbb [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ce19d736c8a4451fbfda411024669fbb" member_type: VOTER last_known_addr { host: "127.26.251.65" port: 45841 } }
I20260812 06:17:55.261902 27935 leader_election.cc:304] T 4cce3831782e468d9bdad5e14d9b457b P ce19d736c8a4451fbfda411024669fbb [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: ce19d736c8a4451fbfda411024669fbb; no voters: 
I20260812 06:17:55.262168 27935 leader_election.cc:290] T 4cce3831782e468d9bdad5e14d9b457b P ce19d736c8a4451fbfda411024669fbb [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:55.262270 27938 raft_consensus.cc:2804] T 4cce3831782e468d9bdad5e14d9b457b P ce19d736c8a4451fbfda411024669fbb [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:55.262450 27938 raft_consensus.cc:697] T 4cce3831782e468d9bdad5e14d9b457b P ce19d736c8a4451fbfda411024669fbb [term 1 LEADER]: Becoming Leader. State: Replica: ce19d736c8a4451fbfda411024669fbb, State: Running, Role: LEADER
I20260812 06:17:55.262557 27935 ts_tablet_manager.cc:1434] T 4cce3831782e468d9bdad5e14d9b457b P ce19d736c8a4451fbfda411024669fbb: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:17:55.262596 27938 consensus_queue.cc:237] T 4cce3831782e468d9bdad5e14d9b457b P ce19d736c8a4451fbfda411024669fbb [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: "ce19d736c8a4451fbfda411024669fbb" member_type: VOTER last_known_addr { host: "127.26.251.65" port: 45841 } }
I20260812 06:17:55.262975 27915 heartbeater.cc:499] Master 127.26.251.126:46213 was elected leader, sending a full tablet report...
I20260812 06:17:55.265439 27678 catalog_manager.cc:5719] T 4cce3831782e468d9bdad5e14d9b457b P ce19d736c8a4451fbfda411024669fbb reported cstate change: term changed from 0 to 1, leader changed from <none> to ce19d736c8a4451fbfda411024669fbb (127.26.251.65). New cstate: current_term: 1 leader_uuid: "ce19d736c8a4451fbfda411024669fbb" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ce19d736c8a4451fbfda411024669fbb" member_type: VOTER last_known_addr { host: "127.26.251.65" port: 45841 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:55.334638 27629 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.060s	user 0.028s	sys 0.004s
I20260812 06:17:55.463310 27917 maintenance_manager.cc:419] P ce19d736c8a4451fbfda411024669fbb: Scheduling FlushMRSOp(4cce3831782e468d9bdad5e14d9b457b): perf score=17.070565
I20260812 06:17:55.646674 27809 maintenance_manager.cc:643] P ce19d736c8a4451fbfda411024669fbb: FlushMRSOp(4cce3831782e468d9bdad5e14d9b457b) complete. Timing: real 0.183s	user 0.125s	sys 0.056s Metrics: {"bytes_written":12676713,"cfile_init":1,"compiler_manager_pool.queue_time_us":374,"delete_count":0,"dirs.queue_time_us":50,"dirs.run_cpu_time_us":238,"dirs.run_wall_time_us":891,"drs_written":1,"lbm_read_time_us":74,"lbm_reads_lt_1ms":4,"lbm_write_time_us":45484,"lbm_writes_lt_1ms":766,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":321920,"thread_start_us":134,"threads_started":1,"update_count":1545}
I20260812 06:17:55.647832 27917 maintenance_manager.cc:419] P ce19d736c8a4451fbfda411024669fbb: Scheduling LogGCOp(4cce3831782e468d9bdad5e14d9b457b): free 20743880 bytes of WAL
I20260812 06:17:55.648196 27809 log_reader.cc:385] T 4cce3831782e468d9bdad5e14d9b457b: removed 2 log segments from log reader
I20260812 06:17:55.648273 27809 log.cc:1079] T 4cce3831782e468d9bdad5e14d9b457b P ce19d736c8a4451fbfda411024669fbb: Deleting log segment in path: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475050180-27629-0/minicluster-data/ts-0-root/wals/4cce3831782e468d9bdad5e14d9b457b/wal-000000001 (ops 1-6)
I20260812 06:17:55.648336 27809 log.cc:1079] T 4cce3831782e468d9bdad5e14d9b457b P ce19d736c8a4451fbfda411024669fbb: Deleting log segment in path: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475050180-27629-0/minicluster-data/ts-0-root/wals/4cce3831782e468d9bdad5e14d9b457b/wal-000000002 (ops 7-11)
I20260812 06:17:55.653744 27809 maintenance_manager.cc:643] P ce19d736c8a4451fbfda411024669fbb: LogGCOp(4cce3831782e468d9bdad5e14d9b457b) complete. Timing: real 0.006s	user 0.001s	sys 0.003s Metrics: {}
I20260812 06:17:55.654210 27917 maintenance_manager.cc:419] P ce19d736c8a4451fbfda411024669fbb: Scheduling FlushDeltaMemStoresOp(4cce3831782e468d9bdad5e14d9b457b): perf score=2.188937
I20260812 06:17:55.674899 27809 maintenance_manager.cc:643] P ce19d736c8a4451fbfda411024669fbb: FlushDeltaMemStoresOp(4cce3831782e468d9bdad5e14d9b457b) complete. Timing: real 0.021s	user 0.004s	sys 0.014s Metrics: {"bytes_written":4143687,"delete_count":0,"lbm_write_time_us":5372,"lbm_writes_lt_1ms":104,"reinsert_count":0,"update_count":505}
I20260812 06:17:55.675457 27917 maintenance_manager.cc:419] P ce19d736c8a4451fbfda411024669fbb: Scheduling UndoDeltaBlockGCOp(4cce3831782e468d9bdad5e14d9b457b): 16411392 bytes on disk
I20260812 06:17:55.676168 27809 maintenance_manager.cc:643] P ce19d736c8a4451fbfda411024669fbb: UndoDeltaBlockGCOp(4cce3831782e468d9bdad5e14d9b457b) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":79,"lbm_reads_lt_1ms":4}
I20260812 06:17:55.676610 27917 maintenance_manager.cc:419] P ce19d736c8a4451fbfda411024669fbb: Scheduling FlushDeltaMemStoresOp(4cce3831782e468d9bdad5e14d9b457b): perf score=2.188937
I20260812 06:17:55.691507 27809 maintenance_manager.cc:643] P ce19d736c8a4451fbfda411024669fbb: FlushDeltaMemStoresOp(4cce3831782e468d9bdad5e14d9b457b) complete. Timing: real 0.015s	user 0.013s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5709,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:55.692050 27917 maintenance_manager.cc:419] P ce19d736c8a4451fbfda411024669fbb: Scheduling MajorDeltaCompactionOp(4cce3831782e468d9bdad5e14d9b457b): perf score=1.000000
I20260812 06:17:55.865025 27809 maintenance_manager.cc:643] P ce19d736c8a4451fbfda411024669fbb: MajorDeltaCompactionOp(4cce3831782e468d9bdad5e14d9b457b) complete. Timing: real 0.173s	user 0.128s	sys 0.044s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774805,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":581,"lbm_read_time_us":12957,"lbm_reads_lt_1ms":569,"lbm_write_time_us":28843,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"thread_start_us":299,"threads_started":5,"update_count":2500}
I20260812 06:17:55.865506 27917 maintenance_manager.cc:419] P ce19d736c8a4451fbfda411024669fbb: Scheduling FlushDeltaMemStoresOp(4cce3831782e468d9bdad5e14d9b457b): perf score=10.126437
I20260812 06:17:55.906105 27809 maintenance_manager.cc:643] P ce19d736c8a4451fbfda411024669fbb: FlushDeltaMemStoresOp(4cce3831782e468d9bdad5e14d9b457b) complete. Timing: real 0.040s	user 0.026s	sys 0.013s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18170,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:55.906615 27917 maintenance_manager.cc:419] P ce19d736c8a4451fbfda411024669fbb: Scheduling FlushDeltaMemStoresOp(4cce3831782e468d9bdad5e14d9b457b): perf score=2.188937
I20260812 06:17:55.916822 27809 maintenance_manager.cc:643] P ce19d736c8a4451fbfda411024669fbb: FlushDeltaMemStoresOp(4cce3831782e468d9bdad5e14d9b457b) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4041,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:55.917253 27917 maintenance_manager.cc:419] P ce19d736c8a4451fbfda411024669fbb: Scheduling MajorDeltaCompactionOp(4cce3831782e468d9bdad5e14d9b457b): perf score=1.000000
I20260812 06:17:56.060815 27809 maintenance_manager.cc:643] P ce19d736c8a4451fbfda411024669fbb: MajorDeltaCompactionOp(4cce3831782e468d9bdad5e14d9b457b) complete. Timing: real 0.143s	user 0.099s	sys 0.037s 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":686,"lbm_read_time_us":8986,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27902,"lbm_writes_lt_1ms":443,"mutex_wait_us":75,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:17:56.061473 27917 maintenance_manager.cc:419] P ce19d736c8a4451fbfda411024669fbb: Scheduling FlushDeltaMemStoresOp(4cce3831782e468d9bdad5e14d9b457b): perf score=10.126437
I20260812 06:17:56.109715 27809 maintenance_manager.cc:643] P ce19d736c8a4451fbfda411024669fbb: FlushDeltaMemStoresOp(4cce3831782e468d9bdad5e14d9b457b) complete. Timing: real 0.048s	user 0.026s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15828,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:56.110193 27917 maintenance_manager.cc:419] P ce19d736c8a4451fbfda411024669fbb: Scheduling FlushDeltaMemStoresOp(4cce3831782e468d9bdad5e14d9b457b): perf score=2.188937
I20260812 06:17:56.121014 27809 maintenance_manager.cc:643] P ce19d736c8a4451fbfda411024669fbb: FlushDeltaMemStoresOp(4cce3831782e468d9bdad5e14d9b457b) complete. Timing: real 0.011s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4070,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:56.121788 27917 maintenance_manager.cc:419] P ce19d736c8a4451fbfda411024669fbb: Scheduling MajorDeltaCompactionOp(4cce3831782e468d9bdad5e14d9b457b): perf score=1.000000
I20260812 06:17:56.240742 27809 maintenance_manager.cc:643] P ce19d736c8a4451fbfda411024669fbb: MajorDeltaCompactionOp(4cce3831782e468d9bdad5e14d9b457b) complete. Timing: real 0.119s	user 0.095s	sys 0.024s 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":853,"lbm_read_time_us":8533,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22642,"lbm_writes_lt_1ms":443,"mutex_wait_us":200,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":14336,"update_count":2000}
I20260812 06:17:56.241376 27917 maintenance_manager.cc:419] P ce19d736c8a4451fbfda411024669fbb: Scheduling FlushDeltaMemStoresOp(4cce3831782e468d9bdad5e14d9b457b): perf score=10.126437
I20260812 06:17:56.287493 27809 maintenance_manager.cc:643] P ce19d736c8a4451fbfda411024669fbb: FlushDeltaMemStoresOp(4cce3831782e468d9bdad5e14d9b457b) complete. Timing: real 0.046s	user 0.029s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19384,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:56.287997 27917 maintenance_manager.cc:419] P ce19d736c8a4451fbfda411024669fbb: Scheduling FlushDeltaMemStoresOp(4cce3831782e468d9bdad5e14d9b457b): perf score=2.188937
I20260812 06:17:56.298491 27809 maintenance_manager.cc:643] P ce19d736c8a4451fbfda411024669fbb: FlushDeltaMemStoresOp(4cce3831782e468d9bdad5e14d9b457b) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3893,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:56.299106 27917 maintenance_manager.cc:419] P ce19d736c8a4451fbfda411024669fbb: Scheduling MajorDeltaCompactionOp(4cce3831782e468d9bdad5e14d9b457b): perf score=1.000000
I20260812 06:17:56.424682 27809 maintenance_manager.cc:643] P ce19d736c8a4451fbfda411024669fbb: MajorDeltaCompactionOp(4cce3831782e468d9bdad5e14d9b457b) complete. Timing: real 0.125s	user 0.101s	sys 0.024s 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":230,"lbm_read_time_us":9194,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24588,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":18048,"update_count":2000}
I20260812 06:17:56.425190 27917 maintenance_manager.cc:419] P ce19d736c8a4451fbfda411024669fbb: Scheduling FlushDeltaMemStoresOp(4cce3831782e468d9bdad5e14d9b457b): perf score=10.126437
I20260812 06:17:56.480815 27809 maintenance_manager.cc:643] P ce19d736c8a4451fbfda411024669fbb: FlushDeltaMemStoresOp(4cce3831782e468d9bdad5e14d9b457b) complete. Timing: real 0.055s	user 0.035s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17445,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:56.481371 27917 maintenance_manager.cc:419] P ce19d736c8a4451fbfda411024669fbb: Scheduling FlushDeltaMemStoresOp(4cce3831782e468d9bdad5e14d9b457b): perf score=2.188937
I20260812 06:17:56.492430 27809 maintenance_manager.cc:643] P ce19d736c8a4451fbfda411024669fbb: FlushDeltaMemStoresOp(4cce3831782e468d9bdad5e14d9b457b) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4172,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:56.492976 27917 maintenance_manager.cc:419] P ce19d736c8a4451fbfda411024669fbb: Scheduling MajorDeltaCompactionOp(4cce3831782e468d9bdad5e14d9b457b): perf score=1.000000
I20260812 06:17:56.634819 27809 maintenance_manager.cc:643] P ce19d736c8a4451fbfda411024669fbb: MajorDeltaCompactionOp(4cce3831782e468d9bdad5e14d9b457b) complete. Timing: real 0.142s	user 0.118s	sys 0.024s 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":408,"lbm_read_time_us":11082,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23130,"lbm_writes_lt_1ms":443,"mutex_wait_us":99,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:56.635509 27917 maintenance_manager.cc:419] P ce19d736c8a4451fbfda411024669fbb: Scheduling FlushDeltaMemStoresOp(4cce3831782e468d9bdad5e14d9b457b): perf score=10.126437
I20260812 06:17:56.671810 27809 maintenance_manager.cc:643] P ce19d736c8a4451fbfda411024669fbb: FlushDeltaMemStoresOp(4cce3831782e468d9bdad5e14d9b457b) complete. Timing: real 0.036s	user 0.028s	sys 0.004s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15377,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:56.672474 27917 maintenance_manager.cc:419] P ce19d736c8a4451fbfda411024669fbb: Scheduling FlushDeltaMemStoresOp(4cce3831782e468d9bdad5e14d9b457b): perf score=2.188937
I20260812 06:17:56.687844 27809 maintenance_manager.cc:643] P ce19d736c8a4451fbfda411024669fbb: FlushDeltaMemStoresOp(4cce3831782e468d9bdad5e14d9b457b) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5691,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:56.688452 27917 maintenance_manager.cc:419] P ce19d736c8a4451fbfda411024669fbb: Scheduling MajorDeltaCompactionOp(4cce3831782e468d9bdad5e14d9b457b): perf score=1.000000
I20260812 06:17:56.827471 27809 maintenance_manager.cc:643] P ce19d736c8a4451fbfda411024669fbb: MajorDeltaCompactionOp(4cce3831782e468d9bdad5e14d9b457b) complete. Timing: real 0.139s	user 0.093s	sys 0.045s 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":335,"lbm_read_time_us":10111,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26779,"lbm_writes_lt_1ms":443,"mutex_wait_us":1,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":2000}
I20260812 06:17:56.828254 27917 maintenance_manager.cc:419] P ce19d736c8a4451fbfda411024669fbb: Scheduling FlushDeltaMemStoresOp(4cce3831782e468d9bdad5e14d9b457b): perf score=10.126437
I20260812 06:17:56.872678 27809 maintenance_manager.cc:643] P ce19d736c8a4451fbfda411024669fbb: FlushDeltaMemStoresOp(4cce3831782e468d9bdad5e14d9b457b) complete. Timing: real 0.044s	user 0.033s	sys 0.005s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":16324,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:56.873199 27917 maintenance_manager.cc:419] P ce19d736c8a4451fbfda411024669fbb: Scheduling FlushDeltaMemStoresOp(4cce3831782e468d9bdad5e14d9b457b): perf score=2.188937
I20260812 06:17:56.884689 27809 maintenance_manager.cc:643] P ce19d736c8a4451fbfda411024669fbb: FlushDeltaMemStoresOp(4cce3831782e468d9bdad5e14d9b457b) complete. Timing: real 0.011s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4175,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:56.885221 27917 maintenance_manager.cc:419] P ce19d736c8a4451fbfda411024669fbb: Scheduling FlushMRSOp(4cce3831782e468d9bdad5e14d9b457b): perf score=1.000000
I20260812 06:17:56.918041 27809 maintenance_manager.cc:643] P ce19d736c8a4451fbfda411024669fbb: FlushMRSOp(4cce3831782e468d9bdad5e14d9b457b) complete. Timing: real 0.033s	user 0.031s	sys 0.000s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":83,"dirs.run_cpu_time_us":328,"dirs.run_wall_time_us":1424,"drs_written":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1578,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:17:56.918862 27917 maintenance_manager.cc:419] P ce19d736c8a4451fbfda411024669fbb: Scheduling LogGCOp(4cce3831782e468d9bdad5e14d9b457b): free 112239310 bytes of WAL
I20260812 06:17:56.919127 27809 log_reader.cc:385] T 4cce3831782e468d9bdad5e14d9b457b: removed 11 log segments from log reader
I20260812 06:17:56.919176 27809 log.cc:1079] T 4cce3831782e468d9bdad5e14d9b457b P ce19d736c8a4451fbfda411024669fbb: Deleting log segment in path: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475050180-27629-0/minicluster-data/ts-0-root/wals/4cce3831782e468d9bdad5e14d9b457b/wal-000000003 (ops 12-16)
I20260812 06:17:56.919207 27809 log.cc:1079] T 4cce3831782e468d9bdad5e14d9b457b P ce19d736c8a4451fbfda411024669fbb: Deleting log segment in path: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475050180-27629-0/minicluster-data/ts-0-root/wals/4cce3831782e468d9bdad5e14d9b457b/wal-000000004 (ops 17-21)
I20260812 06:17:56.919343 27809 log.cc:1079] T 4cce3831782e468d9bdad5e14d9b457b P ce19d736c8a4451fbfda411024669fbb: Deleting log segment in path: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475050180-27629-0/minicluster-data/ts-0-root/wals/4cce3831782e468d9bdad5e14d9b457b/wal-000000005 (ops 22-26)
I20260812 06:17:56.919402 27809 log.cc:1079] T 4cce3831782e468d9bdad5e14d9b457b P ce19d736c8a4451fbfda411024669fbb: Deleting log segment in path: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475050180-27629-0/minicluster-data/ts-0-root/wals/4cce3831782e468d9bdad5e14d9b457b/wal-000000006 (ops 27-30)
I20260812 06:17:56.919447 27809 log.cc:1079] T 4cce3831782e468d9bdad5e14d9b457b P ce19d736c8a4451fbfda411024669fbb: Deleting log segment in path: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475050180-27629-0/minicluster-data/ts-0-root/wals/4cce3831782e468d9bdad5e14d9b457b/wal-000000007 (ops 31-35)
I20260812 06:17:56.919504 27809 log.cc:1079] T 4cce3831782e468d9bdad5e14d9b457b P ce19d736c8a4451fbfda411024669fbb: Deleting log segment in path: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475050180-27629-0/minicluster-data/ts-0-root/wals/4cce3831782e468d9bdad5e14d9b457b/wal-000000008 (ops 36-40)
I20260812 06:17:56.919543 27809 log.cc:1079] T 4cce3831782e468d9bdad5e14d9b457b P ce19d736c8a4451fbfda411024669fbb: Deleting log segment in path: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475050180-27629-0/minicluster-data/ts-0-root/wals/4cce3831782e468d9bdad5e14d9b457b/wal-000000009 (ops 41-45)
I20260812 06:17:56.919581 27809 log.cc:1079] T 4cce3831782e468d9bdad5e14d9b457b P ce19d736c8a4451fbfda411024669fbb: Deleting log segment in path: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475050180-27629-0/minicluster-data/ts-0-root/wals/4cce3831782e468d9bdad5e14d9b457b/wal-000000010 (ops 46-50)
I20260812 06:17:56.919620 27809 log.cc:1079] T 4cce3831782e468d9bdad5e14d9b457b P ce19d736c8a4451fbfda411024669fbb: Deleting log segment in path: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475050180-27629-0/minicluster-data/ts-0-root/wals/4cce3831782e468d9bdad5e14d9b457b/wal-000000011 (ops 51-55)
I20260812 06:17:56.919659 27809 log.cc:1079] T 4cce3831782e468d9bdad5e14d9b457b P ce19d736c8a4451fbfda411024669fbb: Deleting log segment in path: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475050180-27629-0/minicluster-data/ts-0-root/wals/4cce3831782e468d9bdad5e14d9b457b/wal-000000012 (ops 56-60)
I20260812 06:17:56.919698 27809 log.cc:1079] T 4cce3831782e468d9bdad5e14d9b457b P ce19d736c8a4451fbfda411024669fbb: Deleting log segment in path: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475050180-27629-0/minicluster-data/ts-0-root/wals/4cce3831782e468d9bdad5e14d9b457b/wal-000000013 (ops 61-65)
I20260812 06:17:56.944690 27809 maintenance_manager.cc:643] P ce19d736c8a4451fbfda411024669fbb: LogGCOp(4cce3831782e468d9bdad5e14d9b457b) complete. Timing: real 0.026s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:17:56.945117 27917 maintenance_manager.cc:419] P ce19d736c8a4451fbfda411024669fbb: Scheduling FlushDeltaMemStoresOp(4cce3831782e468d9bdad5e14d9b457b): perf score=3.181125
I20260812 06:17:56.965246 27809 maintenance_manager.cc:643] P ce19d736c8a4451fbfda411024669fbb: FlushDeltaMemStoresOp(4cce3831782e468d9bdad5e14d9b457b) complete. Timing: real 0.020s	user 0.006s	sys 0.011s Metrics: {"bytes_written":4512902,"delete_count":0,"lbm_write_time_us":7010,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:56.965675 27917 maintenance_manager.cc:419] P ce19d736c8a4451fbfda411024669fbb: Scheduling LogGCOp(4cce3831782e468d9bdad5e14d9b457b): free 12017932 bytes of WAL
I20260812 06:17:56.965883 27809 log_reader.cc:385] T 4cce3831782e468d9bdad5e14d9b457b: removed 1 log segments from log reader
I20260812 06:17:56.965927 27809 log.cc:1079] T 4cce3831782e468d9bdad5e14d9b457b P ce19d736c8a4451fbfda411024669fbb: Deleting log segment in path: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475050180-27629-0/minicluster-data/ts-0-root/wals/4cce3831782e468d9bdad5e14d9b457b/wal-000000014 (ops 66-70)
I20260812 06:17:56.968348 27809 maintenance_manager.cc:643] P ce19d736c8a4451fbfda411024669fbb: LogGCOp(4cce3831782e468d9bdad5e14d9b457b) complete. Timing: real 0.003s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:17:56.968626 27917 maintenance_manager.cc:419] P ce19d736c8a4451fbfda411024669fbb: Scheduling FlushDeltaMemStoresOp(4cce3831782e468d9bdad5e14d9b457b): perf score=2.188937
I20260812 06:17:56.977833 27809 maintenance_manager.cc:643] P ce19d736c8a4451fbfda411024669fbb: FlushDeltaMemStoresOp(4cce3831782e468d9bdad5e14d9b457b) complete. Timing: real 0.009s	user 0.006s	sys 0.002s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3505,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:56.978394 27917 maintenance_manager.cc:419] P ce19d736c8a4451fbfda411024669fbb: Scheduling UndoDeltaBlockGCOp(4cce3831782e468d9bdad5e14d9b457b): 463 bytes on disk
I20260812 06:17:56.979008 27809 maintenance_manager.cc:643] P ce19d736c8a4451fbfda411024669fbb: UndoDeltaBlockGCOp(4cce3831782e468d9bdad5e14d9b457b) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":111,"lbm_reads_lt_1ms":4}
I20260812 06:17:56.979693 27917 maintenance_manager.cc:419] P ce19d736c8a4451fbfda411024669fbb: Scheduling MajorDeltaCompactionOp(4cce3831782e468d9bdad5e14d9b457b): perf score=1.000000
I20260812 06:17:57.166569 27809 maintenance_manager.cc:643] P ce19d736c8a4451fbfda411024669fbb: MajorDeltaCompactionOp(4cce3831782e468d9bdad5e14d9b457b) complete. Timing: real 0.187s	user 0.125s	sys 0.055s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877331,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":239,"lbm_read_time_us":13955,"lbm_reads_lt_1ms":674,"lbm_write_time_us":38859,"lbm_writes_lt_1ms":643,"mutex_wait_us":22,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":12160,"thread_start_us":92,"threads_started":1,"update_count":3000}
I20260812 06:17:57.167213 27917 maintenance_manager.cc:419] P ce19d736c8a4451fbfda411024669fbb: Scheduling FlushDeltaMemStoresOp(4cce3831782e468d9bdad5e14d9b457b): perf score=14.095187
I20260812 06:17:57.222787 27809 maintenance_manager.cc:643] P ce19d736c8a4451fbfda411024669fbb: FlushDeltaMemStoresOp(4cce3831782e468d9bdad5e14d9b457b) complete. Timing: real 0.055s	user 0.032s	sys 0.019s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":26265,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2000}
I20260812 06:17:57.223357 27917 maintenance_manager.cc:419] P ce19d736c8a4451fbfda411024669fbb: Scheduling FlushDeltaMemStoresOp(4cce3831782e468d9bdad5e14d9b457b): perf score=2.188937
I20260812 06:17:57.235386 27809 maintenance_manager.cc:643] P ce19d736c8a4451fbfda411024669fbb: FlushDeltaMemStoresOp(4cce3831782e468d9bdad5e14d9b457b) complete. Timing: real 0.012s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4588,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:57.236001 27917 maintenance_manager.cc:419] P ce19d736c8a4451fbfda411024669fbb: Scheduling MajorDeltaCompactionOp(4cce3831782e468d9bdad5e14d9b457b): perf score=1.000000
I20260812 06:17:57.393882 27809 maintenance_manager.cc:643] P ce19d736c8a4451fbfda411024669fbb: MajorDeltaCompactionOp(4cce3831782e468d9bdad5e14d9b457b) complete. Timing: real 0.158s	user 0.119s	sys 0.032s 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":312,"lbm_read_time_us":10733,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30678,"lbm_writes_lt_1ms":543,"mutex_wait_us":71,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5888,"update_count":2500}
I20260812 06:17:57.394619 27917 maintenance_manager.cc:419] P ce19d736c8a4451fbfda411024669fbb: Scheduling FlushDeltaMemStoresOp(4cce3831782e468d9bdad5e14d9b457b): perf score=14.095187
I20260812 06:17:57.447798 27809 maintenance_manager.cc:643] P ce19d736c8a4451fbfda411024669fbb: FlushDeltaMemStoresOp(4cce3831782e468d9bdad5e14d9b457b) complete. Timing: real 0.053s	user 0.045s	sys 0.004s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24296,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:57.448448 27917 maintenance_manager.cc:419] P ce19d736c8a4451fbfda411024669fbb: Scheduling FlushDeltaMemStoresOp(4cce3831782e468d9bdad5e14d9b457b): perf score=2.188937
I20260812 06:17:57.465790 27809 maintenance_manager.cc:643] P ce19d736c8a4451fbfda411024669fbb: FlushDeltaMemStoresOp(4cce3831782e468d9bdad5e14d9b457b) complete. Timing: real 0.017s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6331,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:57.466363 27917 maintenance_manager.cc:419] P ce19d736c8a4451fbfda411024669fbb: Scheduling MajorDeltaCompactionOp(4cce3831782e468d9bdad5e14d9b457b): perf score=1.000000
I20260812 06:17:57.633330 27809 maintenance_manager.cc:643] P ce19d736c8a4451fbfda411024669fbb: MajorDeltaCompactionOp(4cce3831782e468d9bdad5e14d9b457b) complete. Timing: real 0.167s	user 0.123s	sys 0.031s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":606,"lbm_read_time_us":11535,"lbm_reads_lt_1ms":568,"lbm_write_time_us":29969,"lbm_writes_lt_1ms":543,"mutex_wait_us":30,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4224,"update_count":2500}
I20260812 06:17:57.634057 27917 maintenance_manager.cc:419] P ce19d736c8a4451fbfda411024669fbb: Scheduling FlushDeltaMemStoresOp(4cce3831782e468d9bdad5e14d9b457b): perf score=14.095187
I20260812 06:17:57.697661 27809 maintenance_manager.cc:643] P ce19d736c8a4451fbfda411024669fbb: FlushDeltaMemStoresOp(4cce3831782e468d9bdad5e14d9b457b) complete. Timing: real 0.061s	user 0.039s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":28149,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:17:57.698233 27917 maintenance_manager.cc:419] P ce19d736c8a4451fbfda411024669fbb: Scheduling FlushDeltaMemStoresOp(4cce3831782e468d9bdad5e14d9b457b): perf score=2.188937
I20260812 06:17:57.714743 27809 maintenance_manager.cc:643] P ce19d736c8a4451fbfda411024669fbb: FlushDeltaMemStoresOp(4cce3831782e468d9bdad5e14d9b457b) complete. Timing: real 0.016s	user 0.015s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6197,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:57.715490 27917 maintenance_manager.cc:419] P ce19d736c8a4451fbfda411024669fbb: Scheduling MajorDeltaCompactionOp(4cce3831782e468d9bdad5e14d9b457b): perf score=1.000000
I20260812 06:17:57.874720 27809 maintenance_manager.cc:643] P ce19d736c8a4451fbfda411024669fbb: MajorDeltaCompactionOp(4cce3831782e468d9bdad5e14d9b457b) complete. Timing: real 0.159s	user 0.109s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":381,"lbm_read_time_us":9569,"lbm_reads_lt_1ms":564,"lbm_write_time_us":31957,"lbm_writes_lt_1ms":543,"mutex_wait_us":27,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":61824,"update_count":2500}
I20260812 06:17:57.875325 27917 maintenance_manager.cc:419] P ce19d736c8a4451fbfda411024669fbb: Scheduling FlushDeltaMemStoresOp(4cce3831782e468d9bdad5e14d9b457b): perf score=14.095187
I20260812 06:17:57.934180 27809 maintenance_manager.cc:643] P ce19d736c8a4451fbfda411024669fbb: FlushDeltaMemStoresOp(4cce3831782e468d9bdad5e14d9b457b) complete. Timing: real 0.059s	user 0.029s	sys 0.027s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":26226,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:57.934710 27917 maintenance_manager.cc:419] P ce19d736c8a4451fbfda411024669fbb: Scheduling FlushDeltaMemStoresOp(4cce3831782e468d9bdad5e14d9b457b): perf score=2.188937
I20260812 06:17:57.948931 27809 maintenance_manager.cc:643] P ce19d736c8a4451fbfda411024669fbb: FlushDeltaMemStoresOp(4cce3831782e468d9bdad5e14d9b457b) complete. Timing: real 0.014s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4988,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:57.949586 27917 maintenance_manager.cc:419] P ce19d736c8a4451fbfda411024669fbb: Scheduling MajorDeltaCompactionOp(4cce3831782e468d9bdad5e14d9b457b): perf score=1.000000
I20260812 06:17:58.131976 27809 maintenance_manager.cc:643] P ce19d736c8a4451fbfda411024669fbb: MajorDeltaCompactionOp(4cce3831782e468d9bdad5e14d9b457b) complete. Timing: real 0.182s	user 0.133s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774691,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":341,"lbm_read_time_us":12389,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30149,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3584,"update_count":2500}
I20260812 06:17:58.132609 27917 maintenance_manager.cc:419] P ce19d736c8a4451fbfda411024669fbb: Scheduling FlushDeltaMemStoresOp(4cce3831782e468d9bdad5e14d9b457b): perf score=14.095187
I20260812 06:17:58.199708 27809 maintenance_manager.cc:643] P ce19d736c8a4451fbfda411024669fbb: FlushDeltaMemStoresOp(4cce3831782e468d9bdad5e14d9b457b) complete. Timing: real 0.067s	user 0.022s	sys 0.031s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":26334,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:58.200282 27917 maintenance_manager.cc:419] P ce19d736c8a4451fbfda411024669fbb: Scheduling FlushDeltaMemStoresOp(4cce3831782e468d9bdad5e14d9b457b): perf score=2.188937
I20260812 06:17:58.211440 27809 maintenance_manager.cc:643] P ce19d736c8a4451fbfda411024669fbb: FlushDeltaMemStoresOp(4cce3831782e468d9bdad5e14d9b457b) complete. Timing: real 0.011s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3973,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:58.212158 27917 maintenance_manager.cc:419] P ce19d736c8a4451fbfda411024669fbb: Scheduling MajorDeltaCompactionOp(4cce3831782e468d9bdad5e14d9b457b): perf score=1.000000
I20260812 06:17:58.386309 27809 maintenance_manager.cc:643] P ce19d736c8a4451fbfda411024669fbb: MajorDeltaCompactionOp(4cce3831782e468d9bdad5e14d9b457b) complete. Timing: real 0.174s	user 0.111s	sys 0.056s 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":276,"lbm_read_time_us":10291,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32074,"lbm_writes_lt_1ms":543,"mutex_wait_us":29,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2500}
I20260812 06:17:58.387040 27917 maintenance_manager.cc:419] P ce19d736c8a4451fbfda411024669fbb: Scheduling FlushDeltaMemStoresOp(4cce3831782e468d9bdad5e14d9b457b): perf score=14.095187
I20260812 06:17:58.449990 27809 maintenance_manager.cc:643] P ce19d736c8a4451fbfda411024669fbb: FlushDeltaMemStoresOp(4cce3831782e468d9bdad5e14d9b457b) complete. Timing: real 0.063s	user 0.045s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":26904,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:58.450546 27917 maintenance_manager.cc:419] P ce19d736c8a4451fbfda411024669fbb: Scheduling FlushDeltaMemStoresOp(4cce3831782e468d9bdad5e14d9b457b): perf score=2.188937
I20260812 06:17:58.463820 27809 maintenance_manager.cc:643] P ce19d736c8a4451fbfda411024669fbb: FlushDeltaMemStoresOp(4cce3831782e468d9bdad5e14d9b457b) complete. Timing: real 0.013s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4908,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:58.464319 27917 maintenance_manager.cc:419] P ce19d736c8a4451fbfda411024669fbb: Scheduling FlushMRSOp(4cce3831782e468d9bdad5e14d9b457b): perf score=1.000000
I20260812 06:17:58.493461 27809 maintenance_manager.cc:643] P ce19d736c8a4451fbfda411024669fbb: FlushMRSOp(4cce3831782e468d9bdad5e14d9b457b) complete. Timing: real 0.029s	user 0.027s	sys 0.001s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":63,"dirs.run_cpu_time_us":236,"dirs.run_wall_time_us":1428,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1611,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:17:58.494171 27917 maintenance_manager.cc:419] P ce19d736c8a4451fbfda411024669fbb: Scheduling LogGCOp(4cce3831782e468d9bdad5e14d9b457b): free 129320468 bytes of WAL
I20260812 06:17:58.494397 27809 log_reader.cc:385] T 4cce3831782e468d9bdad5e14d9b457b: removed 13 log segments from log reader
I20260812 06:17:58.494462 27809 log.cc:1079] T 4cce3831782e468d9bdad5e14d9b457b P ce19d736c8a4451fbfda411024669fbb: Deleting log segment in path: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475050180-27629-0/minicluster-data/ts-0-root/wals/4cce3831782e468d9bdad5e14d9b457b/wal-000000015 (ops 71-75)
I20260812 06:17:58.494535 27809 log.cc:1079] T 4cce3831782e468d9bdad5e14d9b457b P ce19d736c8a4451fbfda411024669fbb: Deleting log segment in path: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475050180-27629-0/minicluster-data/ts-0-root/wals/4cce3831782e468d9bdad5e14d9b457b/wal-000000016 (ops 76-80)
I20260812 06:17:58.494576 27809 log.cc:1079] T 4cce3831782e468d9bdad5e14d9b457b P ce19d736c8a4451fbfda411024669fbb: Deleting log segment in path: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475050180-27629-0/minicluster-data/ts-0-root/wals/4cce3831782e468d9bdad5e14d9b457b/wal-000000017 (ops 81-84)
I20260812 06:17:58.494619 27809 log.cc:1079] T 4cce3831782e468d9bdad5e14d9b457b P ce19d736c8a4451fbfda411024669fbb: Deleting log segment in path: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475050180-27629-0/minicluster-data/ts-0-root/wals/4cce3831782e468d9bdad5e14d9b457b/wal-000000018 (ops 85-89)
I20260812 06:17:58.494654 27809 log.cc:1079] T 4cce3831782e468d9bdad5e14d9b457b P ce19d736c8a4451fbfda411024669fbb: Deleting log segment in path: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475050180-27629-0/minicluster-data/ts-0-root/wals/4cce3831782e468d9bdad5e14d9b457b/wal-000000019 (ops 90-94)
I20260812 06:17:58.494691 27809 log.cc:1079] T 4cce3831782e468d9bdad5e14d9b457b P ce19d736c8a4451fbfda411024669fbb: Deleting log segment in path: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475050180-27629-0/minicluster-data/ts-0-root/wals/4cce3831782e468d9bdad5e14d9b457b/wal-000000020 (ops 95-98)
I20260812 06:17:58.494728 27809 log.cc:1079] T 4cce3831782e468d9bdad5e14d9b457b P ce19d736c8a4451fbfda411024669fbb: Deleting log segment in path: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475050180-27629-0/minicluster-data/ts-0-root/wals/4cce3831782e468d9bdad5e14d9b457b/wal-000000021 (ops 99-103)
I20260812 06:17:58.494765 27809 log.cc:1079] T 4cce3831782e468d9bdad5e14d9b457b P ce19d736c8a4451fbfda411024669fbb: Deleting log segment in path: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475050180-27629-0/minicluster-data/ts-0-root/wals/4cce3831782e468d9bdad5e14d9b457b/wal-000000022 (ops 104-108)
I20260812 06:17:58.494802 27809 log.cc:1079] T 4cce3831782e468d9bdad5e14d9b457b P ce19d736c8a4451fbfda411024669fbb: Deleting log segment in path: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475050180-27629-0/minicluster-data/ts-0-root/wals/4cce3831782e468d9bdad5e14d9b457b/wal-000000023 (ops 109-113)
I20260812 06:17:58.494839 27809 log.cc:1079] T 4cce3831782e468d9bdad5e14d9b457b P ce19d736c8a4451fbfda411024669fbb: Deleting log segment in path: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475050180-27629-0/minicluster-data/ts-0-root/wals/4cce3831782e468d9bdad5e14d9b457b/wal-000000024 (ops 114-118)
I20260812 06:17:58.494876 27809 log.cc:1079] T 4cce3831782e468d9bdad5e14d9b457b P ce19d736c8a4451fbfda411024669fbb: Deleting log segment in path: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475050180-27629-0/minicluster-data/ts-0-root/wals/4cce3831782e468d9bdad5e14d9b457b/wal-000000025 (ops 119-123)
I20260812 06:17:58.494912 27809 log.cc:1079] T 4cce3831782e468d9bdad5e14d9b457b P ce19d736c8a4451fbfda411024669fbb: Deleting log segment in path: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475050180-27629-0/minicluster-data/ts-0-root/wals/4cce3831782e468d9bdad5e14d9b457b/wal-000000026 (ops 124-128)
I20260812 06:17:58.494951 27809 log.cc:1079] T 4cce3831782e468d9bdad5e14d9b457b P ce19d736c8a4451fbfda411024669fbb: Deleting log segment in path: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475050180-27629-0/minicluster-data/ts-0-root/wals/4cce3831782e468d9bdad5e14d9b457b/wal-000000027 (ops 129-133)
I20260812 06:17:58.526639 27809 maintenance_manager.cc:643] P ce19d736c8a4451fbfda411024669fbb: LogGCOp(4cce3831782e468d9bdad5e14d9b457b) complete. Timing: real 0.032s	user 0.000s	sys 0.030s Metrics: {}
I20260812 06:17:58.527132 27917 maintenance_manager.cc:419] P ce19d736c8a4451fbfda411024669fbb: Scheduling UndoDeltaBlockGCOp(4cce3831782e468d9bdad5e14d9b457b): 492 bytes on disk
I20260812 06:17:58.527837 27809 maintenance_manager.cc:643] P ce19d736c8a4451fbfda411024669fbb: UndoDeltaBlockGCOp(4cce3831782e468d9bdad5e14d9b457b) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":75,"lbm_reads_lt_1ms":4}
I20260812 06:17:58.528522 27917 maintenance_manager.cc:419] P ce19d736c8a4451fbfda411024669fbb: Scheduling FlushDeltaMemStoresOp(4cce3831782e468d9bdad5e14d9b457b): perf score=4.173312
I20260812 06:17:58.546584 27809 maintenance_manager.cc:643] P ce19d736c8a4451fbfda411024669fbb: FlushDeltaMemStoresOp(4cce3831782e468d9bdad5e14d9b457b) complete. Timing: real 0.018s	user 0.012s	sys 0.004s Metrics: {"bytes_written":6030802,"delete_count":0,"lbm_write_time_us":7502,"lbm_writes_lt_1ms":150,"reinsert_count":0,"update_count":735}
I20260812 06:17:58.547071 27917 maintenance_manager.cc:419] P ce19d736c8a4451fbfda411024669fbb: Scheduling FlushDeltaMemStoresOp(4cce3831782e468d9bdad5e14d9b457b): perf score=1.196750
I20260812 06:17:58.554886 27809 maintenance_manager.cc:643] P ce19d736c8a4451fbfda411024669fbb: FlushDeltaMemStoresOp(4cce3831782e468d9bdad5e14d9b457b) complete. Timing: real 0.008s	user 0.003s	sys 0.003s Metrics: {"bytes_written":2174479,"delete_count":0,"lbm_write_time_us":2694,"lbm_writes_lt_1ms":56,"reinsert_count":0,"update_count":265}
I20260812 06:17:58.555436 27917 maintenance_manager.cc:419] P ce19d736c8a4451fbfda411024669fbb: Scheduling MajorDeltaCompactionOp(4cce3831782e468d9bdad5e14d9b457b): perf score=1.000000
I20260812 06:17:58.776458 27809 maintenance_manager.cc:643] P ce19d736c8a4451fbfda411024669fbb: MajorDeltaCompactionOp(4cce3831782e468d9bdad5e14d9b457b) complete. Timing: real 0.221s	user 0.133s	sys 0.080s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979708,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":864,"lbm_read_time_us":13818,"lbm_reads_lt_1ms":774,"lbm_write_time_us":40069,"lbm_writes_lt_1ms":743,"mutex_wait_us":221,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":12672,"thread_start_us":82,"threads_started":1,"update_count":3500}
I20260812 06:17:58.778249 27917 maintenance_manager.cc:419] P ce19d736c8a4451fbfda411024669fbb: Scheduling FlushDeltaMemStoresOp(4cce3831782e468d9bdad5e14d9b457b): perf score=18.063937
I20260812 06:17:58.847096 27809 maintenance_manager.cc:643] P ce19d736c8a4451fbfda411024669fbb: FlushDeltaMemStoresOp(4cce3831782e468d9bdad5e14d9b457b) complete. Timing: real 0.069s	user 0.033s	sys 0.028s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":29153,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:58.847674 27917 maintenance_manager.cc:419] P ce19d736c8a4451fbfda411024669fbb: Scheduling FlushDeltaMemStoresOp(4cce3831782e468d9bdad5e14d9b457b): perf score=2.188937
I20260812 06:17:58.862711 27809 maintenance_manager.cc:643] P ce19d736c8a4451fbfda411024669fbb: FlushDeltaMemStoresOp(4cce3831782e468d9bdad5e14d9b457b) complete. Timing: real 0.015s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6207,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:58.863485 27917 maintenance_manager.cc:419] P ce19d736c8a4451fbfda411024669fbb: Scheduling MajorDeltaCompactionOp(4cce3831782e468d9bdad5e14d9b457b): perf score=1.000000
I20260812 06:17:59.026517 27809 maintenance_manager.cc:643] P ce19d736c8a4451fbfda411024669fbb: MajorDeltaCompactionOp(4cce3831782e468d9bdad5e14d9b457b) complete. Timing: real 0.163s	user 0.123s	sys 0.040s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877102,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":244,"lbm_read_time_us":13189,"lbm_reads_lt_1ms":672,"lbm_write_time_us":33209,"lbm_writes_lt_1ms":643,"mutex_wait_us":21,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":10624,"update_count":3000}
I20260812 06:17:59.027127 27917 maintenance_manager.cc:419] P ce19d736c8a4451fbfda411024669fbb: Scheduling FlushDeltaMemStoresOp(4cce3831782e468d9bdad5e14d9b457b): perf score=14.095187
I20260812 06:17:59.078079 27809 maintenance_manager.cc:643] P ce19d736c8a4451fbfda411024669fbb: FlushDeltaMemStoresOp(4cce3831782e468d9bdad5e14d9b457b) complete. Timing: real 0.051s	user 0.029s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21533,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:59.078660 27917 maintenance_manager.cc:419] P ce19d736c8a4451fbfda411024669fbb: Scheduling FlushDeltaMemStoresOp(4cce3831782e468d9bdad5e14d9b457b): perf score=2.188937
I20260812 06:17:59.098934 27809 maintenance_manager.cc:643] P ce19d736c8a4451fbfda411024669fbb: FlushDeltaMemStoresOp(4cce3831782e468d9bdad5e14d9b457b) complete. Timing: real 0.020s	user 0.012s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7131,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:59.099417 27917 maintenance_manager.cc:419] P ce19d736c8a4451fbfda411024669fbb: Scheduling MajorDeltaCompactionOp(4cce3831782e468d9bdad5e14d9b457b): perf score=1.000000
I20260812 06:17:59.259951 27809 maintenance_manager.cc:643] P ce19d736c8a4451fbfda411024669fbb: MajorDeltaCompactionOp(4cce3831782e468d9bdad5e14d9b457b) complete. Timing: real 0.160s	user 0.117s	sys 0.041s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":747,"lbm_read_time_us":9470,"lbm_reads_lt_1ms":564,"lbm_write_time_us":32950,"lbm_writes_lt_1ms":543,"mutex_wait_us":346,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":34432,"update_count":2500}
I20260812 06:17:59.260664 27917 maintenance_manager.cc:419] P ce19d736c8a4451fbfda411024669fbb: Scheduling FlushDeltaMemStoresOp(4cce3831782e468d9bdad5e14d9b457b): perf score=14.095187
I20260812 06:17:59.324231 27809 maintenance_manager.cc:643] P ce19d736c8a4451fbfda411024669fbb: FlushDeltaMemStoresOp(4cce3831782e468d9bdad5e14d9b457b) complete. Timing: real 0.063s	user 0.036s	sys 0.011s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":22781,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:59.324744 27917 maintenance_manager.cc:419] P ce19d736c8a4451fbfda411024669fbb: Scheduling FlushDeltaMemStoresOp(4cce3831782e468d9bdad5e14d9b457b): perf score=2.188937
I20260812 06:17:59.335558 27809 maintenance_manager.cc:643] P ce19d736c8a4451fbfda411024669fbb: FlushDeltaMemStoresOp(4cce3831782e468d9bdad5e14d9b457b) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4221,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:59.336092 27917 maintenance_manager.cc:419] P ce19d736c8a4451fbfda411024669fbb: Scheduling MajorDeltaCompactionOp(4cce3831782e468d9bdad5e14d9b457b): perf score=1.000000
I20260812 06:17:59.526739 27809 maintenance_manager.cc:643] P ce19d736c8a4451fbfda411024669fbb: MajorDeltaCompactionOp(4cce3831782e468d9bdad5e14d9b457b) complete. Timing: real 0.190s	user 0.128s	sys 0.054s 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":208,"lbm_read_time_us":11138,"lbm_reads_lt_1ms":572,"lbm_write_time_us":36918,"lbm_writes_lt_1ms":543,"mutex_wait_us":47,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10496,"update_count":2500}
I20260812 06:17:59.527398 27917 maintenance_manager.cc:419] P ce19d736c8a4451fbfda411024669fbb: Scheduling FlushDeltaMemStoresOp(4cce3831782e468d9bdad5e14d9b457b): perf score=14.095187
I20260812 06:17:59.591315 27809 maintenance_manager.cc:643] P ce19d736c8a4451fbfda411024669fbb: FlushDeltaMemStoresOp(4cce3831782e468d9bdad5e14d9b457b) complete. Timing: real 0.064s	user 0.039s	sys 0.013s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23183,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:59.591914 27917 maintenance_manager.cc:419] P ce19d736c8a4451fbfda411024669fbb: Scheduling FlushDeltaMemStoresOp(4cce3831782e468d9bdad5e14d9b457b): perf score=2.188937
I20260812 06:17:59.604384 27809 maintenance_manager.cc:643] P ce19d736c8a4451fbfda411024669fbb: FlushDeltaMemStoresOp(4cce3831782e468d9bdad5e14d9b457b) complete. Timing: real 0.012s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4444,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:59.604925 27917 maintenance_manager.cc:419] P ce19d736c8a4451fbfda411024669fbb: Scheduling MajorDeltaCompactionOp(4cce3831782e468d9bdad5e14d9b457b): perf score=1.000000
I20260812 06:17:59.774211 27809 maintenance_manager.cc:643] P ce19d736c8a4451fbfda411024669fbb: MajorDeltaCompactionOp(4cce3831782e468d9bdad5e14d9b457b) complete. Timing: real 0.169s	user 0.117s	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":1232,"lbm_read_time_us":12068,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28486,"lbm_writes_lt_1ms":543,"mutex_wait_us":56,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":2500}
I20260812 06:17:59.774725 27917 maintenance_manager.cc:419] P ce19d736c8a4451fbfda411024669fbb: Scheduling FlushDeltaMemStoresOp(4cce3831782e468d9bdad5e14d9b457b): perf score=14.095187
I20260812 06:17:59.842788 27809 maintenance_manager.cc:643] P ce19d736c8a4451fbfda411024669fbb: FlushDeltaMemStoresOp(4cce3831782e468d9bdad5e14d9b457b) complete. Timing: real 0.068s	user 0.025s	sys 0.040s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":29217,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:59.843385 27917 maintenance_manager.cc:419] P ce19d736c8a4451fbfda411024669fbb: Scheduling FlushDeltaMemStoresOp(4cce3831782e468d9bdad5e14d9b457b): perf score=2.188937
I20260812 06:17:59.853977 27809 maintenance_manager.cc:643] P ce19d736c8a4451fbfda411024669fbb: FlushDeltaMemStoresOp(4cce3831782e468d9bdad5e14d9b457b) complete. Timing: real 0.010s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4169,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:59.854445 27917 maintenance_manager.cc:419] P ce19d736c8a4451fbfda411024669fbb: Scheduling FlushMRSOp(4cce3831782e468d9bdad5e14d9b457b): perf score=1.000000
I20260812 06:17:59.894932 27809 maintenance_manager.cc:643] P ce19d736c8a4451fbfda411024669fbb: FlushMRSOp(4cce3831782e468d9bdad5e14d9b457b) complete. Timing: real 0.040s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1152512,"cfile_init":1,"dirs.queue_time_us":66,"dirs.run_cpu_time_us":210,"dirs.run_wall_time_us":1115,"drs_written":1,"lbm_read_time_us":62,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1868,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:17:59.895635 27917 maintenance_manager.cc:419] P ce19d736c8a4451fbfda411024669fbb: Scheduling LogGCOp(4cce3831782e468d9bdad5e14d9b457b): free 112239614 bytes of WAL
I20260812 06:17:59.895860 27809 log_reader.cc:385] T 4cce3831782e468d9bdad5e14d9b457b: removed 11 log segments from log reader
I20260812 06:17:59.895901 27809 log.cc:1079] T 4cce3831782e468d9bdad5e14d9b457b P ce19d736c8a4451fbfda411024669fbb: Deleting log segment in path: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475050180-27629-0/minicluster-data/ts-0-root/wals/4cce3831782e468d9bdad5e14d9b457b/wal-000000028 (ops 134-138)
I20260812 06:17:59.895929 27809 log.cc:1079] T 4cce3831782e468d9bdad5e14d9b457b P ce19d736c8a4451fbfda411024669fbb: Deleting log segment in path: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475050180-27629-0/minicluster-data/ts-0-root/wals/4cce3831782e468d9bdad5e14d9b457b/wal-000000029 (ops 139-143)
I20260812 06:17:59.895985 27809 log.cc:1079] T 4cce3831782e468d9bdad5e14d9b457b P ce19d736c8a4451fbfda411024669fbb: Deleting log segment in path: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475050180-27629-0/minicluster-data/ts-0-root/wals/4cce3831782e468d9bdad5e14d9b457b/wal-000000030 (ops 144-148)
I20260812 06:17:59.896026 27809 log.cc:1079] T 4cce3831782e468d9bdad5e14d9b457b P ce19d736c8a4451fbfda411024669fbb: Deleting log segment in path: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475050180-27629-0/minicluster-data/ts-0-root/wals/4cce3831782e468d9bdad5e14d9b457b/wal-000000031 (ops 149-153)
I20260812 06:17:59.896065 27809 log.cc:1079] T 4cce3831782e468d9bdad5e14d9b457b P ce19d736c8a4451fbfda411024669fbb: Deleting log segment in path: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475050180-27629-0/minicluster-data/ts-0-root/wals/4cce3831782e468d9bdad5e14d9b457b/wal-000000032 (ops 154-158)
I20260812 06:17:59.896121 27809 log.cc:1079] T 4cce3831782e468d9bdad5e14d9b457b P ce19d736c8a4451fbfda411024669fbb: Deleting log segment in path: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475050180-27629-0/minicluster-data/ts-0-root/wals/4cce3831782e468d9bdad5e14d9b457b/wal-000000033 (ops 159-163)
I20260812 06:17:59.896163 27809 log.cc:1079] T 4cce3831782e468d9bdad5e14d9b457b P ce19d736c8a4451fbfda411024669fbb: Deleting log segment in path: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475050180-27629-0/minicluster-data/ts-0-root/wals/4cce3831782e468d9bdad5e14d9b457b/wal-000000034 (ops 164-168)
I20260812 06:17:59.896198 27809 log.cc:1079] T 4cce3831782e468d9bdad5e14d9b457b P ce19d736c8a4451fbfda411024669fbb: Deleting log segment in path: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475050180-27629-0/minicluster-data/ts-0-root/wals/4cce3831782e468d9bdad5e14d9b457b/wal-000000035 (ops 169-173)
I20260812 06:17:59.896234 27809 log.cc:1079] T 4cce3831782e468d9bdad5e14d9b457b P ce19d736c8a4451fbfda411024669fbb: Deleting log segment in path: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475050180-27629-0/minicluster-data/ts-0-root/wals/4cce3831782e468d9bdad5e14d9b457b/wal-000000036 (ops 174-178)
I20260812 06:17:59.896271 27809 log.cc:1079] T 4cce3831782e468d9bdad5e14d9b457b P ce19d736c8a4451fbfda411024669fbb: Deleting log segment in path: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475050180-27629-0/minicluster-data/ts-0-root/wals/4cce3831782e468d9bdad5e14d9b457b/wal-000000037 (ops 179-182)
I20260812 06:17:59.896308 27809 log.cc:1079] T 4cce3831782e468d9bdad5e14d9b457b P ce19d736c8a4451fbfda411024669fbb: Deleting log segment in path: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515475050180-27629-0/minicluster-data/ts-0-root/wals/4cce3831782e468d9bdad5e14d9b457b/wal-000000038 (ops 183-187)
I20260812 06:17:59.921291 27809 maintenance_manager.cc:643] P ce19d736c8a4451fbfda411024669fbb: LogGCOp(4cce3831782e468d9bdad5e14d9b457b) complete. Timing: real 0.025s	user 0.001s	sys 0.023s Metrics: {}
I20260812 06:17:59.921681 27917 maintenance_manager.cc:419] P ce19d736c8a4451fbfda411024669fbb: Scheduling UndoDeltaBlockGCOp(4cce3831782e468d9bdad5e14d9b457b): 447 bytes on disk
I20260812 06:17:59.922113 27809 maintenance_manager.cc:643] P ce19d736c8a4451fbfda411024669fbb: UndoDeltaBlockGCOp(4cce3831782e468d9bdad5e14d9b457b) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4}
I20260812 06:17:59.922660 27917 maintenance_manager.cc:419] P ce19d736c8a4451fbfda411024669fbb: Scheduling FlushDeltaMemStoresOp(4cce3831782e468d9bdad5e14d9b457b): perf score=3.181125
I20260812 06:17:59.946409 27809 maintenance_manager.cc:643] P ce19d736c8a4451fbfda411024669fbb: FlushDeltaMemStoresOp(4cce3831782e468d9bdad5e14d9b457b) complete. Timing: real 0.024s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":6787,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:59.946880 27917 maintenance_manager.cc:419] P ce19d736c8a4451fbfda411024669fbb: Scheduling FlushDeltaMemStoresOp(4cce3831782e468d9bdad5e14d9b457b): perf score=2.188937
I20260812 06:17:59.958058 27809 maintenance_manager.cc:643] P ce19d736c8a4451fbfda411024669fbb: FlushDeltaMemStoresOp(4cce3831782e468d9bdad5e14d9b457b) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4218,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:59.958513 27917 maintenance_manager.cc:419] P ce19d736c8a4451fbfda411024669fbb: Scheduling MajorDeltaCompactionOp(4cce3831782e468d9bdad5e14d9b457b): perf score=1.000000
I20260812 06:18:00.188208 27629 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.853s	user 1.772s	sys 0.161s
I20260812 06:18:00.190618 27809 maintenance_manager.cc:643] P ce19d736c8a4451fbfda411024669fbb: MajorDeltaCompactionOp(4cce3831782e468d9bdad5e14d9b457b) complete. Timing: real 0.232s	user 0.156s	sys 0.068s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979741,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":517,"lbm_read_time_us":15129,"lbm_reads_lt_1ms":774,"lbm_write_time_us":37443,"lbm_writes_lt_1ms":743,"mutex_wait_us":67,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":768,"thread_start_us":119,"threads_started":1,"update_count":3500}
I20260812 06:18:00.191507 27917 maintenance_manager.cc:419] P ce19d736c8a4451fbfda411024669fbb: Scheduling FlushDeltaMemStoresOp(4cce3831782e468d9bdad5e14d9b457b): perf score=18.063937
I20260812 06:18:00.221017 27629 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.032s	user 0.004s	sys 0.000s
I20260812 06:18:00.221793 27629 tablet_server.cc:179] TabletServer@127.26.251.65:0 shutting down...
I20260812 06:18:00.246237 27809 maintenance_manager.cc:643] P ce19d736c8a4451fbfda411024669fbb: FlushDeltaMemStoresOp(4cce3831782e468d9bdad5e14d9b457b) complete. Timing: real 0.054s	user 0.039s	sys 0.012s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":24381,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:00.246961 27629 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:00.247382 27629 tablet_replica.cc:333] T 4cce3831782e468d9bdad5e14d9b457b P ce19d736c8a4451fbfda411024669fbb: stopping tablet replica
I20260812 06:18:00.247640 27629 raft_consensus.cc:2243] T 4cce3831782e468d9bdad5e14d9b457b P ce19d736c8a4451fbfda411024669fbb [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:00.247882 27629 raft_consensus.cc:2272] T 4cce3831782e468d9bdad5e14d9b457b P ce19d736c8a4451fbfda411024669fbb [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:00.263664 27629 tablet_server.cc:196] TabletServer@127.26.251.65:0 shutdown complete.
I20260812 06:18:00.268965 27629 master.cc:562] Master@127.26.251.126:46213 shutting down...
I20260812 06:18:00.272832 27629 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 5d311e4f02bd4bd7aa8d86a39199c040 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:00.273023 27629 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 5d311e4f02bd4bd7aa8d86a39199c040 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:00.273085 27629 tablet_replica.cc:333] T 00000000000000000000000000000000 P 5d311e4f02bd4bd7aa8d86a39199c040: stopping tablet replica
I20260812 06:18:00.285477 27629 master.cc:584] Master@127.26.251.126:46213 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5318 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:18:00.378541 27629 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.26.251.126:40905
I20260812 06:18:00.378898 27629 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:00.381188 27967 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:00.381343 27629 server_base.cc:1061] running on GCE node
W20260812 06:18:00.381261 27968 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:00.381301 27970 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:00.381770 27629 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:00.381815 27629 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:00.381832 27629 hybrid_clock.cc:648] HybridClock initialized: now 1786515480381832 us; error 0 us; skew 500 ppm
I20260812 06:18:00.382671 27629 webserver.cc:533] Webserver started at http://127.26.251.126:37225/ using document root <none> and password file <none>
I20260812 06:18:00.382808 27629 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:00.382848 27629 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:00.382911 27629 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:00.383267 27629 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475050180-27629-0/minicluster-data/master-0-root/instance:
uuid: "43c94848213d473f8c401a911fd1b712"
format_stamp: "Formatted at 2026-08-12 06:18:00 on dist-test-slave-t3q3"
I20260812 06:18:00.384840 27629 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:18:00.385718 27978 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:00.386029 27629 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:00.386098 27629 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475050180-27629-0/minicluster-data/master-0-root
uuid: "43c94848213d473f8c401a911fd1b712"
format_stamp: "Formatted at 2026-08-12 06:18:00 on dist-test-slave-t3q3"
I20260812 06:18:00.386191 27629 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475050180-27629-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475050180-27629-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475050180-27629-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:00.395668 27629 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:00.396153 27629 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:00.400532 27629 rpc_server.cc:307] RPC server started. Bound to: 127.26.251.126:40905
I20260812 06:18:00.402614 28068 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:00.403234 28067 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.26.251.126:40905 every 8 connection(s)
I20260812 06:18:00.419242 28068 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 43c94848213d473f8c401a911fd1b712: Bootstrap starting.
I20260812 06:18:00.420315 28068 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 43c94848213d473f8c401a911fd1b712: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:00.421515 28068 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 43c94848213d473f8c401a911fd1b712: No bootstrap required, opened a new log
I20260812 06:18:00.421967 28068 raft_consensus.cc:359] T 00000000000000000000000000000000 P 43c94848213d473f8c401a911fd1b712 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "43c94848213d473f8c401a911fd1b712" member_type: VOTER }
I20260812 06:18:00.422072 28068 raft_consensus.cc:385] T 00000000000000000000000000000000 P 43c94848213d473f8c401a911fd1b712 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:00.422142 28068 raft_consensus.cc:740] T 00000000000000000000000000000000 P 43c94848213d473f8c401a911fd1b712 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 43c94848213d473f8c401a911fd1b712, State: Initialized, Role: FOLLOWER
I20260812 06:18:00.422358 28068 consensus_queue.cc:260] T 00000000000000000000000000000000 P 43c94848213d473f8c401a911fd1b712 [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: "43c94848213d473f8c401a911fd1b712" member_type: VOTER }
I20260812 06:18:00.422463 28068 raft_consensus.cc:399] T 00000000000000000000000000000000 P 43c94848213d473f8c401a911fd1b712 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:00.422539 28068 raft_consensus.cc:493] T 00000000000000000000000000000000 P 43c94848213d473f8c401a911fd1b712 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:00.422609 28068 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 43c94848213d473f8c401a911fd1b712 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:00.423415 28068 raft_consensus.cc:515] T 00000000000000000000000000000000 P 43c94848213d473f8c401a911fd1b712 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "43c94848213d473f8c401a911fd1b712" member_type: VOTER }
I20260812 06:18:00.423580 28068 leader_election.cc:304] T 00000000000000000000000000000000 P 43c94848213d473f8c401a911fd1b712 [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: 43c94848213d473f8c401a911fd1b712; no voters: 
I20260812 06:18:00.423837 28068 leader_election.cc:290] T 00000000000000000000000000000000 P 43c94848213d473f8c401a911fd1b712 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:00.424098 28073 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 43c94848213d473f8c401a911fd1b712 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:00.424372 28073 raft_consensus.cc:697] T 00000000000000000000000000000000 P 43c94848213d473f8c401a911fd1b712 [term 1 LEADER]: Becoming Leader. State: Replica: 43c94848213d473f8c401a911fd1b712, State: Running, Role: LEADER
I20260812 06:18:00.424404 28068 sys_catalog.cc:565] T 00000000000000000000000000000000 P 43c94848213d473f8c401a911fd1b712 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:00.424535 28073 consensus_queue.cc:237] T 00000000000000000000000000000000 P 43c94848213d473f8c401a911fd1b712 [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: "43c94848213d473f8c401a911fd1b712" member_type: VOTER }
I20260812 06:18:00.424988 28077 sys_catalog.cc:455] T 00000000000000000000000000000000 P 43c94848213d473f8c401a911fd1b712 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "43c94848213d473f8c401a911fd1b712" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "43c94848213d473f8c401a911fd1b712" member_type: VOTER } }
I20260812 06:18:00.425001 28078 sys_catalog.cc:455] T 00000000000000000000000000000000 P 43c94848213d473f8c401a911fd1b712 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 43c94848213d473f8c401a911fd1b712. Latest consensus state: current_term: 1 leader_uuid: "43c94848213d473f8c401a911fd1b712" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "43c94848213d473f8c401a911fd1b712" member_type: VOTER } }
I20260812 06:18:00.425096 28077 sys_catalog.cc:458] T 00000000000000000000000000000000 P 43c94848213d473f8c401a911fd1b712 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:00.425119 28078 sys_catalog.cc:458] T 00000000000000000000000000000000 P 43c94848213d473f8c401a911fd1b712 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:00.425366 28084 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:00.426220 28084 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:00.426667 27629 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:00.428225 28084 catalog_manager.cc:1383] Generated new cluster ID: bc1be60fe940409596a2c6c7936ac7e7
I20260812 06:18:00.428285 28084 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:00.445976 28084 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:00.446559 28084 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:00.454439 28084 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 43c94848213d473f8c401a911fd1b712: Generated new TSK 0
I20260812 06:18:00.454608 28084 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:00.459048 27629 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:00.461105 28111 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:00.461202 28109 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:00.461270 27629 server_base.cc:1061] running on GCE node
W20260812 06:18:00.461130 28108 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:00.461535 27629 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:00.461583 27629 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:00.461601 27629 hybrid_clock.cc:648] HybridClock initialized: now 1786515480461600 us; error 0 us; skew 500 ppm
I20260812 06:18:00.462476 27629 webserver.cc:533] Webserver started at http://127.26.251.65:45627/ using document root <none> and password file <none>
I20260812 06:18:00.462666 27629 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:00.462735 27629 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:00.462817 27629 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:00.463276 27629 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475050180-27629-0/minicluster-data/ts-0-root/instance:
uuid: "10090ffadd054a31a2df225c9fd3b846"
format_stamp: "Formatted at 2026-08-12 06:18:00 on dist-test-slave-t3q3"
I20260812 06:18:00.464838 27629 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:18:00.465739 28118 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:00.465971 27629 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:18:00.466065 27629 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475050180-27629-0/minicluster-data/ts-0-root
uuid: "10090ffadd054a31a2df225c9fd3b846"
format_stamp: "Formatted at 2026-08-12 06:18:00 on dist-test-slave-t3q3"
I20260812 06:18:00.466161 27629 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475050180-27629-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475050180-27629-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475050180-27629-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:00.474483 27629 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:00.474840 27629 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:00.475145 27629 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:00.475613 27629 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:00.475677 27629 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:00.475739 27629 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:00.475773 27629 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:00.480108 27629 rpc_server.cc:307] RPC server started. Bound to: 127.26.251.65:35593
I20260812 06:18:00.480175 28227 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.26.251.65:35593 every 8 connection(s)
I20260812 06:18:00.487706 28231 heartbeater.cc:344] Connected to a master server at 127.26.251.126:40905
I20260812 06:18:00.487816 28231 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:00.488013 28231 heartbeater.cc:507] Master 127.26.251.126:40905 requested a full tablet report, sending...
I20260812 06:18:00.488708 28008 ts_manager.cc:194] Registered new tserver with Master: 10090ffadd054a31a2df225c9fd3b846 (127.26.251.65:35593)
I20260812 06:18:00.489454 27629 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.008860667s
I20260812 06:18:00.489514 28008 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:57932
I20260812 06:18:00.496958 28008 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:57948:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:18:00.505947 28172 tablet_service.cc:1511] Processing CreateTablet for tablet a18e75e1b7f04d51aafdf222c8b15771 (DEFAULT_TABLE table=heavy-update-compaction-test [id=ad216f68103949eeb62f6559f43719cc]), partition=
I20260812 06:18:00.506193 28172 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet a18e75e1b7f04d51aafdf222c8b15771. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:00.508025 28246 tablet_bootstrap.cc:492] T a18e75e1b7f04d51aafdf222c8b15771 P 10090ffadd054a31a2df225c9fd3b846: Bootstrap starting.
I20260812 06:18:00.508961 28246 tablet_bootstrap.cc:654] T a18e75e1b7f04d51aafdf222c8b15771 P 10090ffadd054a31a2df225c9fd3b846: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:00.510010 28246 tablet_bootstrap.cc:492] T a18e75e1b7f04d51aafdf222c8b15771 P 10090ffadd054a31a2df225c9fd3b846: No bootstrap required, opened a new log
I20260812 06:18:00.510111 28246 ts_tablet_manager.cc:1403] T a18e75e1b7f04d51aafdf222c8b15771 P 10090ffadd054a31a2df225c9fd3b846: Time spent bootstrapping tablet: real 0.002s	user 0.000s	sys 0.001s
I20260812 06:18:00.510543 28246 raft_consensus.cc:359] T a18e75e1b7f04d51aafdf222c8b15771 P 10090ffadd054a31a2df225c9fd3b846 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "10090ffadd054a31a2df225c9fd3b846" member_type: VOTER last_known_addr { host: "127.26.251.65" port: 35593 } }
I20260812 06:18:00.510638 28246 raft_consensus.cc:385] T a18e75e1b7f04d51aafdf222c8b15771 P 10090ffadd054a31a2df225c9fd3b846 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:00.510661 28246 raft_consensus.cc:740] T a18e75e1b7f04d51aafdf222c8b15771 P 10090ffadd054a31a2df225c9fd3b846 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 10090ffadd054a31a2df225c9fd3b846, State: Initialized, Role: FOLLOWER
I20260812 06:18:00.510852 28246 consensus_queue.cc:260] T a18e75e1b7f04d51aafdf222c8b15771 P 10090ffadd054a31a2df225c9fd3b846 [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: "10090ffadd054a31a2df225c9fd3b846" member_type: VOTER last_known_addr { host: "127.26.251.65" port: 35593 } }
I20260812 06:18:00.510959 28246 raft_consensus.cc:399] T a18e75e1b7f04d51aafdf222c8b15771 P 10090ffadd054a31a2df225c9fd3b846 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:00.511008 28246 raft_consensus.cc:493] T a18e75e1b7f04d51aafdf222c8b15771 P 10090ffadd054a31a2df225c9fd3b846 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:00.511065 28246 raft_consensus.cc:3060] T a18e75e1b7f04d51aafdf222c8b15771 P 10090ffadd054a31a2df225c9fd3b846 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:00.511924 28246 raft_consensus.cc:515] T a18e75e1b7f04d51aafdf222c8b15771 P 10090ffadd054a31a2df225c9fd3b846 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "10090ffadd054a31a2df225c9fd3b846" member_type: VOTER last_known_addr { host: "127.26.251.65" port: 35593 } }
I20260812 06:18:00.512039 28246 leader_election.cc:304] T a18e75e1b7f04d51aafdf222c8b15771 P 10090ffadd054a31a2df225c9fd3b846 [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: 10090ffadd054a31a2df225c9fd3b846; no voters: 
I20260812 06:18:00.512269 28246 leader_election.cc:290] T a18e75e1b7f04d51aafdf222c8b15771 P 10090ffadd054a31a2df225c9fd3b846 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:00.512403 28250 raft_consensus.cc:2804] T a18e75e1b7f04d51aafdf222c8b15771 P 10090ffadd054a31a2df225c9fd3b846 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:00.512658 28231 heartbeater.cc:499] Master 127.26.251.126:40905 was elected leader, sending a full tablet report...
I20260812 06:18:00.512633 28250 raft_consensus.cc:697] T a18e75e1b7f04d51aafdf222c8b15771 P 10090ffadd054a31a2df225c9fd3b846 [term 1 LEADER]: Becoming Leader. State: Replica: 10090ffadd054a31a2df225c9fd3b846, State: Running, Role: LEADER
I20260812 06:18:00.512646 28246 ts_tablet_manager.cc:1434] T a18e75e1b7f04d51aafdf222c8b15771 P 10090ffadd054a31a2df225c9fd3b846: Time spent starting tablet: real 0.002s	user 0.002s	sys 0.001s
I20260812 06:18:00.512795 28250 consensus_queue.cc:237] T a18e75e1b7f04d51aafdf222c8b15771 P 10090ffadd054a31a2df225c9fd3b846 [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: "10090ffadd054a31a2df225c9fd3b846" member_type: VOTER last_known_addr { host: "127.26.251.65" port: 35593 } }
I20260812 06:18:00.514087 28008 catalog_manager.cc:5719] T a18e75e1b7f04d51aafdf222c8b15771 P 10090ffadd054a31a2df225c9fd3b846 reported cstate change: term changed from 0 to 1, leader changed from <none> to 10090ffadd054a31a2df225c9fd3b846 (127.26.251.65). New cstate: current_term: 1 leader_uuid: "10090ffadd054a31a2df225c9fd3b846" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "10090ffadd054a31a2df225c9fd3b846" member_type: VOTER last_known_addr { host: "127.26.251.65" port: 35593 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:00.575228 27629 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.054s	user 0.017s	sys 0.008s
I20260812 06:18:00.731163 28232 maintenance_manager.cc:419] P 10090ffadd054a31a2df225c9fd3b846: Scheduling FlushMRSOp(a18e75e1b7f04d51aafdf222c8b15771): perf score=19.054940
I20260812 06:18:00.892136 28129 maintenance_manager.cc:643] P 10090ffadd054a31a2df225c9fd3b846: FlushMRSOp(a18e75e1b7f04d51aafdf222c8b15771) complete. Timing: real 0.161s	user 0.097s	sys 0.062s Metrics: {"bytes_written":13169000,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":65,"dirs.run_cpu_time_us":164,"dirs.run_wall_time_us":769,"drs_written":1,"lbm_read_time_us":59,"lbm_reads_lt_1ms":4,"lbm_write_time_us":39531,"lbm_writes_lt_1ms":788,"mutex_wait_us":1851,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"spinlock_wait_cycles":16256,"update_count":1605}
I20260812 06:18:00.892926 28232 maintenance_manager.cc:419] P 10090ffadd054a31a2df225c9fd3b846: Scheduling LogGCOp(a18e75e1b7f04d51aafdf222c8b15771): free 20743831 bytes of WAL
I20260812 06:18:00.893267 28129 log_reader.cc:385] T a18e75e1b7f04d51aafdf222c8b15771: removed 2 log segments from log reader
I20260812 06:18:00.893349 28129 log.cc:1079] T a18e75e1b7f04d51aafdf222c8b15771 P 10090ffadd054a31a2df225c9fd3b846: Deleting log segment in path: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475050180-27629-0/minicluster-data/ts-0-root/wals/a18e75e1b7f04d51aafdf222c8b15771/wal-000000001 (ops 1-6)
I20260812 06:18:00.893402 28129 log.cc:1079] T a18e75e1b7f04d51aafdf222c8b15771 P 10090ffadd054a31a2df225c9fd3b846: Deleting log segment in path: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475050180-27629-0/minicluster-data/ts-0-root/wals/a18e75e1b7f04d51aafdf222c8b15771/wal-000000002 (ops 7-11)
I20260812 06:18:00.898397 28129 maintenance_manager.cc:643] P 10090ffadd054a31a2df225c9fd3b846: LogGCOp(a18e75e1b7f04d51aafdf222c8b15771) complete. Timing: real 0.005s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:18:00.898790 28232 maintenance_manager.cc:419] P 10090ffadd054a31a2df225c9fd3b846: Scheduling UndoDeltaBlockGCOp(a18e75e1b7f04d51aafdf222c8b15771): 16821646 bytes on disk
I20260812 06:18:00.899227 28129 maintenance_manager.cc:643] P 10090ffadd054a31a2df225c9fd3b846: UndoDeltaBlockGCOp(a18e75e1b7f04d51aafdf222c8b15771) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4}
I20260812 06:18:00.899847 28232 maintenance_manager.cc:419] P 10090ffadd054a31a2df225c9fd3b846: Scheduling FlushDeltaMemStoresOp(a18e75e1b7f04d51aafdf222c8b15771): perf score=2.188937
I20260812 06:18:00.911716 28129 maintenance_manager.cc:643] P 10090ffadd054a31a2df225c9fd3b846: FlushDeltaMemStoresOp(a18e75e1b7f04d51aafdf222c8b15771) complete. Timing: real 0.012s	user 0.003s	sys 0.004s Metrics: {"bytes_written":3241134,"delete_count":0,"lbm_write_time_us":3166,"lbm_writes_lt_1ms":82,"reinsert_count":0,"update_count":395}
I20260812 06:18:00.912210 28232 maintenance_manager.cc:419] P 10090ffadd054a31a2df225c9fd3b846: Scheduling FlushDeltaMemStoresOp(a18e75e1b7f04d51aafdf222c8b15771): perf score=2.188937
I20260812 06:18:00.921505 28129 maintenance_manager.cc:643] P 10090ffadd054a31a2df225c9fd3b846: FlushDeltaMemStoresOp(a18e75e1b7f04d51aafdf222c8b15771) complete. Timing: real 0.009s	user 0.002s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3530,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:00.921905 28232 maintenance_manager.cc:419] P 10090ffadd054a31a2df225c9fd3b846: Scheduling MajorDeltaCompactionOp(a18e75e1b7f04d51aafdf222c8b15771): perf score=1.000000
I20260812 06:18:01.095240 28129 maintenance_manager.cc:643] P 10090ffadd054a31a2df225c9fd3b846: MajorDeltaCompactionOp(a18e75e1b7f04d51aafdf222c8b15771) complete. Timing: real 0.173s	user 0.133s	sys 0.035s Metrics: {"cfile_cache_miss":523,"cfile_cache_miss_bytes":24405534,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":532,"lbm_read_time_us":12219,"lbm_reads_lt_1ms":559,"lbm_write_time_us":31134,"lbm_writes_lt_1ms":533,"peak_mem_usage":61665166,"reinsert_count":0,"spinlock_wait_cycles":768,"thread_start_us":349,"threads_started":5,"update_count":2450}
I20260812 06:18:01.095796 28232 maintenance_manager.cc:419] P 10090ffadd054a31a2df225c9fd3b846: Scheduling FlushDeltaMemStoresOp(a18e75e1b7f04d51aafdf222c8b15771): perf score=14.095187
I20260812 06:18:01.153927 28129 maintenance_manager.cc:643] P 10090ffadd054a31a2df225c9fd3b846: FlushDeltaMemStoresOp(a18e75e1b7f04d51aafdf222c8b15771) complete. Timing: real 0.058s	user 0.032s	sys 0.019s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":23450,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:01.154390 28232 maintenance_manager.cc:419] P 10090ffadd054a31a2df225c9fd3b846: Scheduling FlushDeltaMemStoresOp(a18e75e1b7f04d51aafdf222c8b15771): perf score=2.188937
I20260812 06:18:01.166232 28129 maintenance_manager.cc:643] P 10090ffadd054a31a2df225c9fd3b846: FlushDeltaMemStoresOp(a18e75e1b7f04d51aafdf222c8b15771) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3968,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:01.166815 28232 maintenance_manager.cc:419] P 10090ffadd054a31a2df225c9fd3b846: Scheduling MajorDeltaCompactionOp(a18e75e1b7f04d51aafdf222c8b15771): perf score=1.000000
I20260812 06:18:01.327442 28129 maintenance_manager.cc:643] P 10090ffadd054a31a2df225c9fd3b846: MajorDeltaCompactionOp(a18e75e1b7f04d51aafdf222c8b15771) complete. Timing: real 0.160s	user 0.104s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":220,"lbm_read_time_us":10197,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29373,"lbm_writes_lt_1ms":543,"mutex_wait_us":76,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":15872,"update_count":2500}
I20260812 06:18:01.328241 28232 maintenance_manager.cc:419] P 10090ffadd054a31a2df225c9fd3b846: Scheduling FlushDeltaMemStoresOp(a18e75e1b7f04d51aafdf222c8b15771): perf score=14.095187
I20260812 06:18:01.383700 28129 maintenance_manager.cc:643] P 10090ffadd054a31a2df225c9fd3b846: FlushDeltaMemStoresOp(a18e75e1b7f04d51aafdf222c8b15771) complete. Timing: real 0.055s	user 0.034s	sys 0.017s Metrics: {"bytes_written":16409899,"delete_count":0,"lbm_write_time_us":24239,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:01.384271 28232 maintenance_manager.cc:419] P 10090ffadd054a31a2df225c9fd3b846: Scheduling MajorDeltaCompactionOp(a18e75e1b7f04d51aafdf222c8b15771): perf score=1.000000
I20260812 06:18:01.528551 28129 maintenance_manager.cc:643] P 10090ffadd054a31a2df225c9fd3b846: MajorDeltaCompactionOp(a18e75e1b7f04d51aafdf222c8b15771) complete. Timing: real 0.144s	user 0.083s	sys 0.061s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713150,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":193,"lbm_read_time_us":10354,"lbm_reads_lt_1ms":463,"lbm_write_time_us":22723,"lbm_writes_lt_1ms":443,"mutex_wait_us":40,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7808,"update_count":2000}
I20260812 06:18:01.529341 28232 maintenance_manager.cc:419] P 10090ffadd054a31a2df225c9fd3b846: Scheduling FlushDeltaMemStoresOp(a18e75e1b7f04d51aafdf222c8b15771): perf score=14.095187
I20260812 06:18:01.581100 28129 maintenance_manager.cc:643] P 10090ffadd054a31a2df225c9fd3b846: FlushDeltaMemStoresOp(a18e75e1b7f04d51aafdf222c8b15771) complete. Timing: real 0.052s	user 0.022s	sys 0.027s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":23204,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:01.581646 28232 maintenance_manager.cc:419] P 10090ffadd054a31a2df225c9fd3b846: Scheduling FlushDeltaMemStoresOp(a18e75e1b7f04d51aafdf222c8b15771): perf score=2.188937
I20260812 06:18:01.593899 28129 maintenance_manager.cc:643] P 10090ffadd054a31a2df225c9fd3b846: FlushDeltaMemStoresOp(a18e75e1b7f04d51aafdf222c8b15771) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4543,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:01.594367 28232 maintenance_manager.cc:419] P 10090ffadd054a31a2df225c9fd3b846: Scheduling MajorDeltaCompactionOp(a18e75e1b7f04d51aafdf222c8b15771): perf score=1.000000
I20260812 06:18:01.784008 28129 maintenance_manager.cc:643] P 10090ffadd054a31a2df225c9fd3b846: MajorDeltaCompactionOp(a18e75e1b7f04d51aafdf222c8b15771) complete. Timing: real 0.189s	user 0.124s	sys 0.061s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":197,"lbm_read_time_us":12333,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30532,"lbm_writes_lt_1ms":543,"mutex_wait_us":41,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":23552,"update_count":2500}
I20260812 06:18:01.784736 28232 maintenance_manager.cc:419] P 10090ffadd054a31a2df225c9fd3b846: Scheduling FlushDeltaMemStoresOp(a18e75e1b7f04d51aafdf222c8b15771): perf score=14.095187
I20260812 06:18:01.836360 28129 maintenance_manager.cc:643] P 10090ffadd054a31a2df225c9fd3b846: FlushDeltaMemStoresOp(a18e75e1b7f04d51aafdf222c8b15771) complete. Timing: real 0.051s	user 0.035s	sys 0.008s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19145,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:01.836928 28232 maintenance_manager.cc:419] P 10090ffadd054a31a2df225c9fd3b846: Scheduling FlushDeltaMemStoresOp(a18e75e1b7f04d51aafdf222c8b15771): perf score=2.188937
I20260812 06:18:01.852587 28129 maintenance_manager.cc:643] P 10090ffadd054a31a2df225c9fd3b846: FlushDeltaMemStoresOp(a18e75e1b7f04d51aafdf222c8b15771) complete. Timing: real 0.015s	user 0.015s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6063,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:01.853084 28232 maintenance_manager.cc:419] P 10090ffadd054a31a2df225c9fd3b846: Scheduling MajorDeltaCompactionOp(a18e75e1b7f04d51aafdf222c8b15771): perf score=1.000000
I20260812 06:18:02.029703 28129 maintenance_manager.cc:643] P 10090ffadd054a31a2df225c9fd3b846: MajorDeltaCompactionOp(a18e75e1b7f04d51aafdf222c8b15771) complete. Timing: real 0.176s	user 0.124s	sys 0.048s 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":241,"lbm_read_time_us":12843,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34878,"lbm_writes_lt_1ms":543,"mutex_wait_us":22,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8576,"update_count":2500}
I20260812 06:18:02.030444 28232 maintenance_manager.cc:419] P 10090ffadd054a31a2df225c9fd3b846: Scheduling FlushDeltaMemStoresOp(a18e75e1b7f04d51aafdf222c8b15771): perf score=11.118625
I20260812 06:18:02.066871 28129 maintenance_manager.cc:643] P 10090ffadd054a31a2df225c9fd3b846: FlushDeltaMemStoresOp(a18e75e1b7f04d51aafdf222c8b15771) complete. Timing: real 0.036s	user 0.018s	sys 0.015s Metrics: {"bytes_written":12635686,"delete_count":0,"lbm_write_time_us":15510,"lbm_writes_lt_1ms":311,"reinsert_count":0,"update_count":1540}
I20260812 06:18:02.067500 28232 maintenance_manager.cc:419] P 10090ffadd054a31a2df225c9fd3b846: Scheduling FlushDeltaMemStoresOp(a18e75e1b7f04d51aafdf222c8b15771): perf score=2.188937
I20260812 06:18:02.084470 28129 maintenance_manager.cc:643] P 10090ffadd054a31a2df225c9fd3b846: FlushDeltaMemStoresOp(a18e75e1b7f04d51aafdf222c8b15771) complete. Timing: real 0.017s	user 0.014s	sys 0.000s Metrics: {"bytes_written":3774458,"delete_count":0,"lbm_write_time_us":5808,"lbm_writes_lt_1ms":95,"reinsert_count":0,"update_count":460}
I20260812 06:18:02.084923 28232 maintenance_manager.cc:419] P 10090ffadd054a31a2df225c9fd3b846: Scheduling FlushMRSOp(a18e75e1b7f04d51aafdf222c8b15771): perf score=1.000000
I20260812 06:18:02.135422 28129 maintenance_manager.cc:643] P 10090ffadd054a31a2df225c9fd3b846: FlushMRSOp(a18e75e1b7f04d51aafdf222c8b15771) complete. Timing: real 0.050s	user 0.027s	sys 0.000s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":74,"dirs.run_cpu_time_us":284,"dirs.run_wall_time_us":1246,"drs_written":1,"lbm_read_time_us":63,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2131,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:02.136298 28232 maintenance_manager.cc:419] P 10090ffadd054a31a2df225c9fd3b846: Scheduling LogGCOp(a18e75e1b7f04d51aafdf222c8b15771): free 115943229 bytes of WAL
I20260812 06:18:02.136562 28129 log_reader.cc:385] T a18e75e1b7f04d51aafdf222c8b15771: removed 11 log segments from log reader
I20260812 06:18:02.136637 28129 log.cc:1079] T a18e75e1b7f04d51aafdf222c8b15771 P 10090ffadd054a31a2df225c9fd3b846: Deleting log segment in path: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475050180-27629-0/minicluster-data/ts-0-root/wals/a18e75e1b7f04d51aafdf222c8b15771/wal-000000003 (ops 12-16)
I20260812 06:18:02.136694 28129 log.cc:1079] T a18e75e1b7f04d51aafdf222c8b15771 P 10090ffadd054a31a2df225c9fd3b846: Deleting log segment in path: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475050180-27629-0/minicluster-data/ts-0-root/wals/a18e75e1b7f04d51aafdf222c8b15771/wal-000000004 (ops 17-21)
I20260812 06:18:02.136751 28129 log.cc:1079] T a18e75e1b7f04d51aafdf222c8b15771 P 10090ffadd054a31a2df225c9fd3b846: Deleting log segment in path: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475050180-27629-0/minicluster-data/ts-0-root/wals/a18e75e1b7f04d51aafdf222c8b15771/wal-000000005 (ops 22-26)
I20260812 06:18:02.136797 28129 log.cc:1079] T a18e75e1b7f04d51aafdf222c8b15771 P 10090ffadd054a31a2df225c9fd3b846: Deleting log segment in path: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475050180-27629-0/minicluster-data/ts-0-root/wals/a18e75e1b7f04d51aafdf222c8b15771/wal-000000006 (ops 27-31)
I20260812 06:18:02.136835 28129 log.cc:1079] T a18e75e1b7f04d51aafdf222c8b15771 P 10090ffadd054a31a2df225c9fd3b846: Deleting log segment in path: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475050180-27629-0/minicluster-data/ts-0-root/wals/a18e75e1b7f04d51aafdf222c8b15771/wal-000000007 (ops 32-36)
I20260812 06:18:02.136874 28129 log.cc:1079] T a18e75e1b7f04d51aafdf222c8b15771 P 10090ffadd054a31a2df225c9fd3b846: Deleting log segment in path: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475050180-27629-0/minicluster-data/ts-0-root/wals/a18e75e1b7f04d51aafdf222c8b15771/wal-000000008 (ops 37-41)
I20260812 06:18:02.136912 28129 log.cc:1079] T a18e75e1b7f04d51aafdf222c8b15771 P 10090ffadd054a31a2df225c9fd3b846: Deleting log segment in path: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475050180-27629-0/minicluster-data/ts-0-root/wals/a18e75e1b7f04d51aafdf222c8b15771/wal-000000009 (ops 42-46)
I20260812 06:18:02.136951 28129 log.cc:1079] T a18e75e1b7f04d51aafdf222c8b15771 P 10090ffadd054a31a2df225c9fd3b846: Deleting log segment in path: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475050180-27629-0/minicluster-data/ts-0-root/wals/a18e75e1b7f04d51aafdf222c8b15771/wal-000000010 (ops 47-51)
I20260812 06:18:02.136991 28129 log.cc:1079] T a18e75e1b7f04d51aafdf222c8b15771 P 10090ffadd054a31a2df225c9fd3b846: Deleting log segment in path: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475050180-27629-0/minicluster-data/ts-0-root/wals/a18e75e1b7f04d51aafdf222c8b15771/wal-000000011 (ops 52-56)
I20260812 06:18:02.137029 28129 log.cc:1079] T a18e75e1b7f04d51aafdf222c8b15771 P 10090ffadd054a31a2df225c9fd3b846: Deleting log segment in path: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475050180-27629-0/minicluster-data/ts-0-root/wals/a18e75e1b7f04d51aafdf222c8b15771/wal-000000012 (ops 57-61)
I20260812 06:18:02.137066 28129 log.cc:1079] T a18e75e1b7f04d51aafdf222c8b15771 P 10090ffadd054a31a2df225c9fd3b846: Deleting log segment in path: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475050180-27629-0/minicluster-data/ts-0-root/wals/a18e75e1b7f04d51aafdf222c8b15771/wal-000000013 (ops 62-66)
I20260812 06:18:02.163108 28129 maintenance_manager.cc:643] P 10090ffadd054a31a2df225c9fd3b846: LogGCOp(a18e75e1b7f04d51aafdf222c8b15771) complete. Timing: real 0.027s	user 0.001s	sys 0.023s Metrics: {}
I20260812 06:18:02.163740 28232 maintenance_manager.cc:419] P 10090ffadd054a31a2df225c9fd3b846: Scheduling UndoDeltaBlockGCOp(a18e75e1b7f04d51aafdf222c8b15771): 448 bytes on disk
I20260812 06:18:02.164326 28129 maintenance_manager.cc:643] P 10090ffadd054a31a2df225c9fd3b846: UndoDeltaBlockGCOp(a18e75e1b7f04d51aafdf222c8b15771) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":68,"lbm_reads_lt_1ms":4}
I20260812 06:18:02.164928 28232 maintenance_manager.cc:419] P 10090ffadd054a31a2df225c9fd3b846: Scheduling FlushDeltaMemStoresOp(a18e75e1b7f04d51aafdf222c8b15771): perf score=6.157687
I20260812 06:18:02.198230 28129 maintenance_manager.cc:643] P 10090ffadd054a31a2df225c9fd3b846: FlushDeltaMemStoresOp(a18e75e1b7f04d51aafdf222c8b15771) complete. Timing: real 0.033s	user 0.017s	sys 0.014s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":9736,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:18:02.198819 28232 maintenance_manager.cc:419] P 10090ffadd054a31a2df225c9fd3b846: Scheduling FlushDeltaMemStoresOp(a18e75e1b7f04d51aafdf222c8b15771): perf score=2.188937
I20260812 06:18:02.210093 28129 maintenance_manager.cc:643] P 10090ffadd054a31a2df225c9fd3b846: FlushDeltaMemStoresOp(a18e75e1b7f04d51aafdf222c8b15771) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4503,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:02.210554 28232 maintenance_manager.cc:419] P 10090ffadd054a31a2df225c9fd3b846: Scheduling MajorDeltaCompactionOp(a18e75e1b7f04d51aafdf222c8b15771): perf score=1.000000
I20260812 06:18:02.471550 28129 maintenance_manager.cc:643] P 10090ffadd054a31a2df225c9fd3b846: MajorDeltaCompactionOp(a18e75e1b7f04d51aafdf222c8b15771) complete. Timing: real 0.261s	user 0.148s	sys 0.112s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020742,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":590,"lbm_read_time_us":18583,"lbm_reads_lt_1ms":774,"lbm_write_time_us":42126,"lbm_writes_lt_1ms":743,"mutex_wait_us":29,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":21632,"thread_start_us":81,"threads_started":1,"update_count":3500}
I20260812 06:18:02.472239 28232 maintenance_manager.cc:419] P 10090ffadd054a31a2df225c9fd3b846: Scheduling FlushDeltaMemStoresOp(a18e75e1b7f04d51aafdf222c8b15771): perf score=18.063937
I20260812 06:18:02.528012 28129 maintenance_manager.cc:643] P 10090ffadd054a31a2df225c9fd3b846: FlushDeltaMemStoresOp(a18e75e1b7f04d51aafdf222c8b15771) complete. Timing: real 0.056s	user 0.033s	sys 0.016s Metrics: {"bytes_written":20512319,"delete_count":0,"lbm_write_time_us":24252,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:02.528558 28232 maintenance_manager.cc:419] P 10090ffadd054a31a2df225c9fd3b846: Scheduling MajorDeltaCompactionOp(a18e75e1b7f04d51aafdf222c8b15771): perf score=1.000000
I20260812 06:18:02.700740 28129 maintenance_manager.cc:643] P 10090ffadd054a31a2df225c9fd3b846: MajorDeltaCompactionOp(a18e75e1b7f04d51aafdf222c8b15771) complete. Timing: real 0.172s	user 0.120s	sys 0.051s Metrics: {"cfile_cache_miss":531,"cfile_cache_miss_bytes":24815570,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":221,"lbm_read_time_us":12935,"lbm_reads_lt_1ms":563,"lbm_write_time_us":29633,"lbm_writes_lt_1ms":543,"mutex_wait_us":33,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:18:02.701406 28232 maintenance_manager.cc:419] P 10090ffadd054a31a2df225c9fd3b846: Scheduling FlushDeltaMemStoresOp(a18e75e1b7f04d51aafdf222c8b15771): perf score=14.095187
I20260812 06:18:02.762610 28129 maintenance_manager.cc:643] P 10090ffadd054a31a2df225c9fd3b846: FlushDeltaMemStoresOp(a18e75e1b7f04d51aafdf222c8b15771) complete. Timing: real 0.061s	user 0.040s	sys 0.019s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22281,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:02.763334 28232 maintenance_manager.cc:419] P 10090ffadd054a31a2df225c9fd3b846: Scheduling FlushDeltaMemStoresOp(a18e75e1b7f04d51aafdf222c8b15771): perf score=2.188937
I20260812 06:18:02.779232 28129 maintenance_manager.cc:643] P 10090ffadd054a31a2df225c9fd3b846: FlushDeltaMemStoresOp(a18e75e1b7f04d51aafdf222c8b15771) complete. Timing: real 0.016s	user 0.011s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6467,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:02.779843 28232 maintenance_manager.cc:419] P 10090ffadd054a31a2df225c9fd3b846: Scheduling MajorDeltaCompactionOp(a18e75e1b7f04d51aafdf222c8b15771): perf score=1.000000
I20260812 06:18:02.971128 28129 maintenance_manager.cc:643] P 10090ffadd054a31a2df225c9fd3b846: MajorDeltaCompactionOp(a18e75e1b7f04d51aafdf222c8b15771) complete. Timing: real 0.191s	user 0.108s	sys 0.077s 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":677,"lbm_read_time_us":13616,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31469,"lbm_writes_lt_1ms":543,"mutex_wait_us":296,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12416,"update_count":2500}
I20260812 06:18:02.971698 28232 maintenance_manager.cc:419] P 10090ffadd054a31a2df225c9fd3b846: Scheduling FlushDeltaMemStoresOp(a18e75e1b7f04d51aafdf222c8b15771): perf score=14.095187
I20260812 06:18:03.021996 28129 maintenance_manager.cc:643] P 10090ffadd054a31a2df225c9fd3b846: FlushDeltaMemStoresOp(a18e75e1b7f04d51aafdf222c8b15771) complete. Timing: real 0.050s	user 0.032s	sys 0.011s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":19961,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:03.022521 28232 maintenance_manager.cc:419] P 10090ffadd054a31a2df225c9fd3b846: Scheduling FlushDeltaMemStoresOp(a18e75e1b7f04d51aafdf222c8b15771): perf score=2.188937
I20260812 06:18:03.045171 28129 maintenance_manager.cc:643] P 10090ffadd054a31a2df225c9fd3b846: FlushDeltaMemStoresOp(a18e75e1b7f04d51aafdf222c8b15771) complete. Timing: real 0.022s	user 0.006s	sys 0.015s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4219,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:03.045682 28232 maintenance_manager.cc:419] P 10090ffadd054a31a2df225c9fd3b846: Scheduling MajorDeltaCompactionOp(a18e75e1b7f04d51aafdf222c8b15771): perf score=1.000000
I20260812 06:18:03.234217 28129 maintenance_manager.cc:643] P 10090ffadd054a31a2df225c9fd3b846: MajorDeltaCompactionOp(a18e75e1b7f04d51aafdf222c8b15771) complete. Timing: real 0.188s	user 0.118s	sys 0.068s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815686,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":234,"lbm_read_time_us":14242,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32036,"lbm_writes_lt_1ms":543,"mutex_wait_us":39,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:18:03.234843 28232 maintenance_manager.cc:419] P 10090ffadd054a31a2df225c9fd3b846: Scheduling FlushDeltaMemStoresOp(a18e75e1b7f04d51aafdf222c8b15771): perf score=14.095187
I20260812 06:18:03.285557 28129 maintenance_manager.cc:643] P 10090ffadd054a31a2df225c9fd3b846: FlushDeltaMemStoresOp(a18e75e1b7f04d51aafdf222c8b15771) complete. Timing: real 0.051s	user 0.010s	sys 0.031s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19494,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:03.286124 28232 maintenance_manager.cc:419] P 10090ffadd054a31a2df225c9fd3b846: Scheduling FlushDeltaMemStoresOp(a18e75e1b7f04d51aafdf222c8b15771): perf score=2.188937
I20260812 06:18:03.302595 28129 maintenance_manager.cc:643] P 10090ffadd054a31a2df225c9fd3b846: FlushDeltaMemStoresOp(a18e75e1b7f04d51aafdf222c8b15771) complete. Timing: real 0.016s	user 0.001s	sys 0.012s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6183,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:03.303150 28232 maintenance_manager.cc:419] P 10090ffadd054a31a2df225c9fd3b846: Scheduling MajorDeltaCompactionOp(a18e75e1b7f04d51aafdf222c8b15771): perf score=1.000000
I20260812 06:18:03.502938 28129 maintenance_manager.cc:643] P 10090ffadd054a31a2df225c9fd3b846: MajorDeltaCompactionOp(a18e75e1b7f04d51aafdf222c8b15771) complete. Timing: real 0.200s	user 0.144s	sys 0.044s 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":287,"lbm_read_time_us":10899,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34132,"lbm_writes_lt_1ms":543,"mutex_wait_us":46,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":35584,"update_count":2500}
I20260812 06:18:03.503662 28232 maintenance_manager.cc:419] P 10090ffadd054a31a2df225c9fd3b846: Scheduling FlushDeltaMemStoresOp(a18e75e1b7f04d51aafdf222c8b15771): perf score=14.095187
I20260812 06:18:03.552834 28129 maintenance_manager.cc:643] P 10090ffadd054a31a2df225c9fd3b846: FlushDeltaMemStoresOp(a18e75e1b7f04d51aafdf222c8b15771) complete. Timing: real 0.049s	user 0.025s	sys 0.019s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19649,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:03.553411 28232 maintenance_manager.cc:419] P 10090ffadd054a31a2df225c9fd3b846: Scheduling FlushDeltaMemStoresOp(a18e75e1b7f04d51aafdf222c8b15771): perf score=2.188937
I20260812 06:18:03.569200 28129 maintenance_manager.cc:643] P 10090ffadd054a31a2df225c9fd3b846: FlushDeltaMemStoresOp(a18e75e1b7f04d51aafdf222c8b15771) complete. Timing: real 0.016s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5864,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:03.569824 28232 maintenance_manager.cc:419] P 10090ffadd054a31a2df225c9fd3b846: Scheduling MajorDeltaCompactionOp(a18e75e1b7f04d51aafdf222c8b15771): perf score=1.000000
I20260812 06:18:03.720945 28129 maintenance_manager.cc:643] P 10090ffadd054a31a2df225c9fd3b846: MajorDeltaCompactionOp(a18e75e1b7f04d51aafdf222c8b15771) complete. Timing: real 0.151s	user 0.118s	sys 0.031s 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":142,"lbm_read_time_us":12210,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30259,"lbm_writes_lt_1ms":543,"mutex_wait_us":46,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":16512,"update_count":2500}
I20260812 06:18:03.721711 28232 maintenance_manager.cc:419] P 10090ffadd054a31a2df225c9fd3b846: Scheduling FlushDeltaMemStoresOp(a18e75e1b7f04d51aafdf222c8b15771): perf score=11.118625
I20260812 06:18:03.765401 28129 maintenance_manager.cc:643] P 10090ffadd054a31a2df225c9fd3b846: FlushDeltaMemStoresOp(a18e75e1b7f04d51aafdf222c8b15771) complete. Timing: real 0.044s	user 0.027s	sys 0.015s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":18662,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:03.766042 28232 maintenance_manager.cc:419] P 10090ffadd054a31a2df225c9fd3b846: Scheduling FlushDeltaMemStoresOp(a18e75e1b7f04d51aafdf222c8b15771): perf score=2.188937
I20260812 06:18:03.782161 28129 maintenance_manager.cc:643] P 10090ffadd054a31a2df225c9fd3b846: FlushDeltaMemStoresOp(a18e75e1b7f04d51aafdf222c8b15771) complete. Timing: real 0.016s	user 0.001s	sys 0.011s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4855,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:03.782729 28232 maintenance_manager.cc:419] P 10090ffadd054a31a2df225c9fd3b846: Scheduling FlushMRSOp(a18e75e1b7f04d51aafdf222c8b15771): perf score=1.000000
I20260812 06:18:03.834941 28129 maintenance_manager.cc:643] P 10090ffadd054a31a2df225c9fd3b846: FlushMRSOp(a18e75e1b7f04d51aafdf222c8b15771) complete. Timing: real 0.052s	user 0.029s	sys 0.001s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":85,"dirs.run_cpu_time_us":184,"dirs.run_wall_time_us":1181,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1792,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:18:03.835726 28232 maintenance_manager.cc:419] P 10090ffadd054a31a2df225c9fd3b846: Scheduling LogGCOp(a18e75e1b7f04d51aafdf222c8b15771): free 129773569 bytes of WAL
I20260812 06:18:03.835974 28129 log_reader.cc:385] T a18e75e1b7f04d51aafdf222c8b15771: removed 13 log segments from log reader
I20260812 06:18:03.836017 28129 log.cc:1079] T a18e75e1b7f04d51aafdf222c8b15771 P 10090ffadd054a31a2df225c9fd3b846: Deleting log segment in path: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475050180-27629-0/minicluster-data/ts-0-root/wals/a18e75e1b7f04d51aafdf222c8b15771/wal-000000014 (ops 67-71)
I20260812 06:18:03.836047 28129 log.cc:1079] T a18e75e1b7f04d51aafdf222c8b15771 P 10090ffadd054a31a2df225c9fd3b846: Deleting log segment in path: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475050180-27629-0/minicluster-data/ts-0-root/wals/a18e75e1b7f04d51aafdf222c8b15771/wal-000000015 (ops 72-76)
I20260812 06:18:03.836138 28129 log.cc:1079] T a18e75e1b7f04d51aafdf222c8b15771 P 10090ffadd054a31a2df225c9fd3b846: Deleting log segment in path: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475050180-27629-0/minicluster-data/ts-0-root/wals/a18e75e1b7f04d51aafdf222c8b15771/wal-000000016 (ops 77-81)
I20260812 06:18:03.836165 28129 log.cc:1079] T a18e75e1b7f04d51aafdf222c8b15771 P 10090ffadd054a31a2df225c9fd3b846: Deleting log segment in path: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475050180-27629-0/minicluster-data/ts-0-root/wals/a18e75e1b7f04d51aafdf222c8b15771/wal-000000017 (ops 82-86)
I20260812 06:18:03.836208 28129 log.cc:1079] T a18e75e1b7f04d51aafdf222c8b15771 P 10090ffadd054a31a2df225c9fd3b846: Deleting log segment in path: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475050180-27629-0/minicluster-data/ts-0-root/wals/a18e75e1b7f04d51aafdf222c8b15771/wal-000000018 (ops 87-91)
I20260812 06:18:03.836248 28129 log.cc:1079] T a18e75e1b7f04d51aafdf222c8b15771 P 10090ffadd054a31a2df225c9fd3b846: Deleting log segment in path: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475050180-27629-0/minicluster-data/ts-0-root/wals/a18e75e1b7f04d51aafdf222c8b15771/wal-000000019 (ops 92-96)
I20260812 06:18:03.836274 28129 log.cc:1079] T a18e75e1b7f04d51aafdf222c8b15771 P 10090ffadd054a31a2df225c9fd3b846: Deleting log segment in path: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475050180-27629-0/minicluster-data/ts-0-root/wals/a18e75e1b7f04d51aafdf222c8b15771/wal-000000020 (ops 97-100)
I20260812 06:18:03.836311 28129 log.cc:1079] T a18e75e1b7f04d51aafdf222c8b15771 P 10090ffadd054a31a2df225c9fd3b846: Deleting log segment in path: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475050180-27629-0/minicluster-data/ts-0-root/wals/a18e75e1b7f04d51aafdf222c8b15771/wal-000000021 (ops 101-105)
I20260812 06:18:03.836349 28129 log.cc:1079] T a18e75e1b7f04d51aafdf222c8b15771 P 10090ffadd054a31a2df225c9fd3b846: Deleting log segment in path: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475050180-27629-0/minicluster-data/ts-0-root/wals/a18e75e1b7f04d51aafdf222c8b15771/wal-000000022 (ops 106-110)
I20260812 06:18:03.836388 28129 log.cc:1079] T a18e75e1b7f04d51aafdf222c8b15771 P 10090ffadd054a31a2df225c9fd3b846: Deleting log segment in path: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475050180-27629-0/minicluster-data/ts-0-root/wals/a18e75e1b7f04d51aafdf222c8b15771/wal-000000023 (ops 111-115)
I20260812 06:18:03.836428 28129 log.cc:1079] T a18e75e1b7f04d51aafdf222c8b15771 P 10090ffadd054a31a2df225c9fd3b846: Deleting log segment in path: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475050180-27629-0/minicluster-data/ts-0-root/wals/a18e75e1b7f04d51aafdf222c8b15771/wal-000000024 (ops 116-120)
I20260812 06:18:03.836472 28129 log.cc:1079] T a18e75e1b7f04d51aafdf222c8b15771 P 10090ffadd054a31a2df225c9fd3b846: Deleting log segment in path: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475050180-27629-0/minicluster-data/ts-0-root/wals/a18e75e1b7f04d51aafdf222c8b15771/wal-000000025 (ops 121-125)
I20260812 06:18:03.836510 28129 log.cc:1079] T a18e75e1b7f04d51aafdf222c8b15771 P 10090ffadd054a31a2df225c9fd3b846: Deleting log segment in path: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475050180-27629-0/minicluster-data/ts-0-root/wals/a18e75e1b7f04d51aafdf222c8b15771/wal-000000026 (ops 126-130)
I20260812 06:18:03.865433 28129 maintenance_manager.cc:643] P 10090ffadd054a31a2df225c9fd3b846: LogGCOp(a18e75e1b7f04d51aafdf222c8b15771) complete. Timing: real 0.030s	user 0.000s	sys 0.028s Metrics: {}
I20260812 06:18:03.865863 28232 maintenance_manager.cc:419] P 10090ffadd054a31a2df225c9fd3b846: Scheduling FlushDeltaMemStoresOp(a18e75e1b7f04d51aafdf222c8b15771): perf score=7.149875
I20260812 06:18:03.886545 28129 maintenance_manager.cc:643] P 10090ffadd054a31a2df225c9fd3b846: FlushDeltaMemStoresOp(a18e75e1b7f04d51aafdf222c8b15771) complete. Timing: real 0.020s	user 0.013s	sys 0.005s Metrics: {"bytes_written":8615323,"delete_count":0,"lbm_write_time_us":9024,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:18:03.887063 28232 maintenance_manager.cc:419] P 10090ffadd054a31a2df225c9fd3b846: Scheduling FlushDeltaMemStoresOp(a18e75e1b7f04d51aafdf222c8b15771): perf score=2.188937
I20260812 06:18:03.911854 28129 maintenance_manager.cc:643] P 10090ffadd054a31a2df225c9fd3b846: FlushDeltaMemStoresOp(a18e75e1b7f04d51aafdf222c8b15771) complete. Timing: real 0.025s	user 0.010s	sys 0.011s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4803,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:03.912375 28232 maintenance_manager.cc:419] P 10090ffadd054a31a2df225c9fd3b846: Scheduling MajorDeltaCompactionOp(a18e75e1b7f04d51aafdf222c8b15771): perf score=1.000000
I20260812 06:18:04.137432 28129 maintenance_manager.cc:643] P 10090ffadd054a31a2df225c9fd3b846: MajorDeltaCompactionOp(a18e75e1b7f04d51aafdf222c8b15771) complete. Timing: real 0.225s	user 0.154s	sys 0.069s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020730,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":422,"lbm_read_time_us":15753,"lbm_reads_lt_1ms":766,"lbm_write_time_us":37532,"lbm_writes_lt_1ms":743,"mutex_wait_us":39,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":1280,"thread_start_us":84,"threads_started":1,"update_count":3500}
I20260812 06:18:04.148788 28232 maintenance_manager.cc:419] P 10090ffadd054a31a2df225c9fd3b846: Scheduling FlushDeltaMemStoresOp(a18e75e1b7f04d51aafdf222c8b15771): perf score=18.063937
I20260812 06:18:04.231297 28129 maintenance_manager.cc:643] P 10090ffadd054a31a2df225c9fd3b846: FlushDeltaMemStoresOp(a18e75e1b7f04d51aafdf222c8b15771) complete. Timing: real 0.082s	user 0.041s	sys 0.034s Metrics: {"bytes_written":20512318,"delete_count":0,"lbm_write_time_us":38302,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":501,"reinsert_count":0,"update_count":2500}
I20260812 06:18:04.231909 28232 maintenance_manager.cc:419] P 10090ffadd054a31a2df225c9fd3b846: Scheduling FlushDeltaMemStoresOp(a18e75e1b7f04d51aafdf222c8b15771): perf score=3.181125
I20260812 06:18:04.243929 28129 maintenance_manager.cc:643] P 10090ffadd054a31a2df225c9fd3b846: FlushDeltaMemStoresOp(a18e75e1b7f04d51aafdf222c8b15771) complete. Timing: real 0.012s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4449,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:04.244460 28232 maintenance_manager.cc:419] P 10090ffadd054a31a2df225c9fd3b846: Scheduling FlushDeltaMemStoresOp(a18e75e1b7f04d51aafdf222c8b15771): perf score=2.188937
I20260812 06:18:04.253928 28129 maintenance_manager.cc:643] P 10090ffadd054a31a2df225c9fd3b846: FlushDeltaMemStoresOp(a18e75e1b7f04d51aafdf222c8b15771) complete. Timing: real 0.009s	user 0.004s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3552,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:04.254500 28232 maintenance_manager.cc:419] P 10090ffadd054a31a2df225c9fd3b846: Scheduling UndoDeltaBlockGCOp(a18e75e1b7f04d51aafdf222c8b15771): 492 bytes on disk
I20260812 06:18:04.254997 28129 maintenance_manager.cc:643] P 10090ffadd054a31a2df225c9fd3b846: UndoDeltaBlockGCOp(a18e75e1b7f04d51aafdf222c8b15771) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4}
I20260812 06:18:04.255728 28232 maintenance_manager.cc:419] P 10090ffadd054a31a2df225c9fd3b846: Scheduling MajorDeltaCompactionOp(a18e75e1b7f04d51aafdf222c8b15771): perf score=1.000000
I20260812 06:18:04.483790 28129 maintenance_manager.cc:643] P 10090ffadd054a31a2df225c9fd3b846: MajorDeltaCompactionOp(a18e75e1b7f04d51aafdf222c8b15771) complete. Timing: real 0.228s	user 0.144s	sys 0.084s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":33020621,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":624,"lbm_read_time_us":17205,"lbm_reads_lt_1ms":773,"lbm_write_time_us":40218,"lbm_writes_lt_1ms":743,"mutex_wait_us":268,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":3500}
I20260812 06:18:04.484292 28232 maintenance_manager.cc:419] P 10090ffadd054a31a2df225c9fd3b846: Scheduling FlushDeltaMemStoresOp(a18e75e1b7f04d51aafdf222c8b15771): perf score=18.063937
I20260812 06:18:04.545574 28129 maintenance_manager.cc:643] P 10090ffadd054a31a2df225c9fd3b846: FlushDeltaMemStoresOp(a18e75e1b7f04d51aafdf222c8b15771) complete. Timing: real 0.061s	user 0.039s	sys 0.020s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":28031,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:04.546113 28232 maintenance_manager.cc:419] P 10090ffadd054a31a2df225c9fd3b846: Scheduling FlushDeltaMemStoresOp(a18e75e1b7f04d51aafdf222c8b15771): perf score=2.188937
I20260812 06:18:04.558341 28129 maintenance_manager.cc:643] P 10090ffadd054a31a2df225c9fd3b846: FlushDeltaMemStoresOp(a18e75e1b7f04d51aafdf222c8b15771) complete. Timing: real 0.012s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4715,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:04.558940 28232 maintenance_manager.cc:419] P 10090ffadd054a31a2df225c9fd3b846: Scheduling MajorDeltaCompactionOp(a18e75e1b7f04d51aafdf222c8b15771): perf score=1.000000
I20260812 06:18:04.725423 28129 maintenance_manager.cc:643] P 10090ffadd054a31a2df225c9fd3b846: MajorDeltaCompactionOp(a18e75e1b7f04d51aafdf222c8b15771) complete. Timing: real 0.166s	user 0.134s	sys 0.032s 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":345,"lbm_read_time_us":12562,"lbm_reads_lt_1ms":672,"lbm_write_time_us":34881,"lbm_writes_lt_1ms":643,"mutex_wait_us":74,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1536,"update_count":3000}
I20260812 06:18:04.726191 28232 maintenance_manager.cc:419] P 10090ffadd054a31a2df225c9fd3b846: Scheduling FlushDeltaMemStoresOp(a18e75e1b7f04d51aafdf222c8b15771): perf score=14.095187
I20260812 06:18:04.786978 28129 maintenance_manager.cc:643] P 10090ffadd054a31a2df225c9fd3b846: FlushDeltaMemStoresOp(a18e75e1b7f04d51aafdf222c8b15771) complete. Timing: real 0.061s	user 0.026s	sys 0.031s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":27920,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:18:04.787828 28232 maintenance_manager.cc:419] P 10090ffadd054a31a2df225c9fd3b846: Scheduling FlushDeltaMemStoresOp(a18e75e1b7f04d51aafdf222c8b15771): perf score=2.188937
I20260812 06:18:04.804582 28129 maintenance_manager.cc:643] P 10090ffadd054a31a2df225c9fd3b846: FlushDeltaMemStoresOp(a18e75e1b7f04d51aafdf222c8b15771) complete. Timing: real 0.017s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5109,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:04.805081 28232 maintenance_manager.cc:419] P 10090ffadd054a31a2df225c9fd3b846: Scheduling MajorDeltaCompactionOp(a18e75e1b7f04d51aafdf222c8b15771): perf score=1.000000
I20260812 06:18:04.973585 28129 maintenance_manager.cc:643] P 10090ffadd054a31a2df225c9fd3b846: MajorDeltaCompactionOp(a18e75e1b7f04d51aafdf222c8b15771) complete. Timing: real 0.168s	user 0.127s	sys 0.033s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":420,"dirs.run_cpu_time_us":2604,"dirs.run_wall_time_us":17733,"lbm_read_time_us":9442,"lbm_reads_lt_1ms":564,"lbm_write_time_us":30600,"lbm_writes_lt_1ms":543,"mutex_wait_us":34,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:18:04.974231 28232 maintenance_manager.cc:419] P 10090ffadd054a31a2df225c9fd3b846: Scheduling FlushDeltaMemStoresOp(a18e75e1b7f04d51aafdf222c8b15771): perf score=14.095187
I20260812 06:18:05.042475 28129 maintenance_manager.cc:643] P 10090ffadd054a31a2df225c9fd3b846: FlushDeltaMemStoresOp(a18e75e1b7f04d51aafdf222c8b15771) complete. Timing: real 0.068s	user 0.043s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":25236,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:05.043226 28232 maintenance_manager.cc:419] P 10090ffadd054a31a2df225c9fd3b846: Scheduling FlushDeltaMemStoresOp(a18e75e1b7f04d51aafdf222c8b15771): perf score=2.188937
I20260812 06:18:05.057337 28129 maintenance_manager.cc:643] P 10090ffadd054a31a2df225c9fd3b846: FlushDeltaMemStoresOp(a18e75e1b7f04d51aafdf222c8b15771) complete. Timing: real 0.014s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5292,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:05.057863 28232 maintenance_manager.cc:419] P 10090ffadd054a31a2df225c9fd3b846: Scheduling MajorDeltaCompactionOp(a18e75e1b7f04d51aafdf222c8b15771): perf score=1.000000
I20260812 06:18:05.237588 28129 maintenance_manager.cc:643] P 10090ffadd054a31a2df225c9fd3b846: MajorDeltaCompactionOp(a18e75e1b7f04d51aafdf222c8b15771) complete. Timing: real 0.180s	user 0.108s	sys 0.066s 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":303,"lbm_read_time_us":13016,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30748,"lbm_writes_lt_1ms":543,"mutex_wait_us":46,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":24704,"thread_start_us":76,"threads_started":1,"update_count":2500}
I20260812 06:18:05.238420 28232 maintenance_manager.cc:419] P 10090ffadd054a31a2df225c9fd3b846: Scheduling FlushDeltaMemStoresOp(a18e75e1b7f04d51aafdf222c8b15771): perf score=14.095187
I20260812 06:18:05.292284 28129 maintenance_manager.cc:643] P 10090ffadd054a31a2df225c9fd3b846: FlushDeltaMemStoresOp(a18e75e1b7f04d51aafdf222c8b15771) complete. Timing: real 0.054s	user 0.022s	sys 0.032s Metrics: {"bytes_written":16409906,"delete_count":0,"lbm_write_time_us":24977,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:05.292822 28232 maintenance_manager.cc:419] P 10090ffadd054a31a2df225c9fd3b846: Scheduling FlushDeltaMemStoresOp(a18e75e1b7f04d51aafdf222c8b15771): perf score=2.188937
I20260812 06:18:05.306300 28129 maintenance_manager.cc:643] P 10090ffadd054a31a2df225c9fd3b846: FlushDeltaMemStoresOp(a18e75e1b7f04d51aafdf222c8b15771) complete. Timing: real 0.013s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4856,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:05.306919 28232 maintenance_manager.cc:419] P 10090ffadd054a31a2df225c9fd3b846: Scheduling FlushMRSOp(a18e75e1b7f04d51aafdf222c8b15771): perf score=1.000000
I20260812 06:18:05.342568 28129 maintenance_manager.cc:643] P 10090ffadd054a31a2df225c9fd3b846: FlushMRSOp(a18e75e1b7f04d51aafdf222c8b15771) complete. Timing: real 0.035s	user 0.031s	sys 0.000s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":107,"dirs.run_cpu_time_us":244,"dirs.run_wall_time_us":1334,"drs_written":1,"lbm_read_time_us":72,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2079,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:18:05.343353 28232 maintenance_manager.cc:419] P 10090ffadd054a31a2df225c9fd3b846: Scheduling LogGCOp(a18e75e1b7f04d51aafdf222c8b15771): free 124257449 bytes of WAL
I20260812 06:18:05.343690 28129 log_reader.cc:385] T a18e75e1b7f04d51aafdf222c8b15771: removed 12 log segments from log reader
I20260812 06:18:05.343770 28129 log.cc:1079] T a18e75e1b7f04d51aafdf222c8b15771 P 10090ffadd054a31a2df225c9fd3b846: Deleting log segment in path: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475050180-27629-0/minicluster-data/ts-0-root/wals/a18e75e1b7f04d51aafdf222c8b15771/wal-000000027 (ops 131-135)
I20260812 06:18:05.343824 28129 log.cc:1079] T a18e75e1b7f04d51aafdf222c8b15771 P 10090ffadd054a31a2df225c9fd3b846: Deleting log segment in path: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475050180-27629-0/minicluster-data/ts-0-root/wals/a18e75e1b7f04d51aafdf222c8b15771/wal-000000028 (ops 136-140)
I20260812 06:18:05.343874 28129 log.cc:1079] T a18e75e1b7f04d51aafdf222c8b15771 P 10090ffadd054a31a2df225c9fd3b846: Deleting log segment in path: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475050180-27629-0/minicluster-data/ts-0-root/wals/a18e75e1b7f04d51aafdf222c8b15771/wal-000000029 (ops 141-145)
I20260812 06:18:05.343904 28129 log.cc:1079] T a18e75e1b7f04d51aafdf222c8b15771 P 10090ffadd054a31a2df225c9fd3b846: Deleting log segment in path: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475050180-27629-0/minicluster-data/ts-0-root/wals/a18e75e1b7f04d51aafdf222c8b15771/wal-000000030 (ops 146-150)
I20260812 06:18:05.343941 28129 log.cc:1079] T a18e75e1b7f04d51aafdf222c8b15771 P 10090ffadd054a31a2df225c9fd3b846: Deleting log segment in path: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475050180-27629-0/minicluster-data/ts-0-root/wals/a18e75e1b7f04d51aafdf222c8b15771/wal-000000031 (ops 151-154)
I20260812 06:18:05.343978 28129 log.cc:1079] T a18e75e1b7f04d51aafdf222c8b15771 P 10090ffadd054a31a2df225c9fd3b846: Deleting log segment in path: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475050180-27629-0/minicluster-data/ts-0-root/wals/a18e75e1b7f04d51aafdf222c8b15771/wal-000000032 (ops 155-159)
I20260812 06:18:05.344005 28129 log.cc:1079] T a18e75e1b7f04d51aafdf222c8b15771 P 10090ffadd054a31a2df225c9fd3b846: Deleting log segment in path: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475050180-27629-0/minicluster-data/ts-0-root/wals/a18e75e1b7f04d51aafdf222c8b15771/wal-000000033 (ops 160-164)
I20260812 06:18:05.344044 28129 log.cc:1079] T a18e75e1b7f04d51aafdf222c8b15771 P 10090ffadd054a31a2df225c9fd3b846: Deleting log segment in path: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475050180-27629-0/minicluster-data/ts-0-root/wals/a18e75e1b7f04d51aafdf222c8b15771/wal-000000034 (ops 165-169)
I20260812 06:18:05.344110 28129 log.cc:1079] T a18e75e1b7f04d51aafdf222c8b15771 P 10090ffadd054a31a2df225c9fd3b846: Deleting log segment in path: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475050180-27629-0/minicluster-data/ts-0-root/wals/a18e75e1b7f04d51aafdf222c8b15771/wal-000000035 (ops 170-174)
I20260812 06:18:05.344147 28129 log.cc:1079] T a18e75e1b7f04d51aafdf222c8b15771 P 10090ffadd054a31a2df225c9fd3b846: Deleting log segment in path: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475050180-27629-0/minicluster-data/ts-0-root/wals/a18e75e1b7f04d51aafdf222c8b15771/wal-000000036 (ops 175-179)
I20260812 06:18:05.344188 28129 log.cc:1079] T a18e75e1b7f04d51aafdf222c8b15771 P 10090ffadd054a31a2df225c9fd3b846: Deleting log segment in path: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475050180-27629-0/minicluster-data/ts-0-root/wals/a18e75e1b7f04d51aafdf222c8b15771/wal-000000037 (ops 180-184)
I20260812 06:18:05.344231 28129 log.cc:1079] T a18e75e1b7f04d51aafdf222c8b15771 P 10090ffadd054a31a2df225c9fd3b846: Deleting log segment in path: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475050180-27629-0/minicluster-data/ts-0-root/wals/a18e75e1b7f04d51aafdf222c8b15771/wal-000000038 (ops 185-189)
I20260812 06:18:05.374516 28129 maintenance_manager.cc:643] P 10090ffadd054a31a2df225c9fd3b846: LogGCOp(a18e75e1b7f04d51aafdf222c8b15771) complete. Timing: real 0.031s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:18:05.375015 28232 maintenance_manager.cc:419] P 10090ffadd054a31a2df225c9fd3b846: Scheduling FlushDeltaMemStoresOp(a18e75e1b7f04d51aafdf222c8b15771): perf score=4.173312
I20260812 06:18:05.393946 28129 maintenance_manager.cc:643] P 10090ffadd054a31a2df225c9fd3b846: FlushDeltaMemStoresOp(a18e75e1b7f04d51aafdf222c8b15771) complete. Timing: real 0.019s	user 0.016s	sys 0.001s Metrics: {"bytes_written":5374417,"delete_count":0,"lbm_write_time_us":7657,"lbm_writes_lt_1ms":134,"reinsert_count":0,"update_count":655}
I20260812 06:18:05.394419 28232 maintenance_manager.cc:419] P 10090ffadd054a31a2df225c9fd3b846: Scheduling LogGCOp(a18e75e1b7f04d51aafdf222c8b15771): free 8767197 bytes of WAL
I20260812 06:18:05.394626 28129 log_reader.cc:385] T a18e75e1b7f04d51aafdf222c8b15771: removed 1 log segments from log reader
I20260812 06:18:05.394690 28129 log.cc:1079] T a18e75e1b7f04d51aafdf222c8b15771 P 10090ffadd054a31a2df225c9fd3b846: Deleting log segment in path: /tmp/dist-test-taskPLEhys/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515475050180-27629-0/minicluster-data/ts-0-root/wals/a18e75e1b7f04d51aafdf222c8b15771/wal-000000039 (ops 190-194)
I20260812 06:18:05.396531 28129 maintenance_manager.cc:643] P 10090ffadd054a31a2df225c9fd3b846: LogGCOp(a18e75e1b7f04d51aafdf222c8b15771) complete. Timing: real 0.002s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:18:05.396799 28232 maintenance_manager.cc:419] P 10090ffadd054a31a2df225c9fd3b846: Scheduling UndoDeltaBlockGCOp(a18e75e1b7f04d51aafdf222c8b15771): 483 bytes on disk
I20260812 06:18:05.397173 28129 maintenance_manager.cc:643] P 10090ffadd054a31a2df225c9fd3b846: UndoDeltaBlockGCOp(a18e75e1b7f04d51aafdf222c8b15771) 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:18:05.397648 28232 maintenance_manager.cc:419] P 10090ffadd054a31a2df225c9fd3b846: Scheduling FlushDeltaMemStoresOp(a18e75e1b7f04d51aafdf222c8b15771): perf score=1.196750
I20260812 06:18:05.408186 28129 maintenance_manager.cc:643] P 10090ffadd054a31a2df225c9fd3b846: FlushDeltaMemStoresOp(a18e75e1b7f04d51aafdf222c8b15771) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":2830880,"delete_count":0,"lbm_write_time_us":3691,"lbm_writes_lt_1ms":72,"reinsert_count":0,"update_count":345}
I20260812 06:18:05.408695 28232 maintenance_manager.cc:419] P 10090ffadd054a31a2df225c9fd3b846: Scheduling MajorDeltaCompactionOp(a18e75e1b7f04d51aafdf222c8b15771): perf score=1.000000
I20260812 06:18:05.531666 27629 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.956s	user 1.823s	sys 0.199s
I20260812 06:18:05.621524 28129 maintenance_manager.cc:643] P 10090ffadd054a31a2df225c9fd3b846: MajorDeltaCompactionOp(a18e75e1b7f04d51aafdf222c8b15771) complete. Timing: real 0.213s	user 0.145s	sys 0.067s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020723,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":948,"lbm_read_time_us":16808,"lbm_reads_lt_1ms":770,"lbm_write_time_us":36287,"lbm_writes_lt_1ms":743,"mutex_wait_us":106,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":29056,"thread_start_us":89,"threads_started":1,"update_count":3500}
I20260812 06:18:05.622159 28232 maintenance_manager.cc:419] P 10090ffadd054a31a2df225c9fd3b846: Scheduling FlushDeltaMemStoresOp(a18e75e1b7f04d51aafdf222c8b15771): perf score=10.126437
I20260812 06:18:05.631048 27629 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.099s	user 0.001s	sys 0.000s
I20260812 06:18:05.631561 27629 tablet_server.cc:179] TabletServer@127.26.251.65:0 shutting down...
I20260812 06:18:05.654496 28129 maintenance_manager.cc:643] P 10090ffadd054a31a2df225c9fd3b846: FlushDeltaMemStoresOp(a18e75e1b7f04d51aafdf222c8b15771) complete. Timing: real 0.032s	user 0.013s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14561,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:05.655087 27629 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:05.655318 27629 tablet_replica.cc:333] T a18e75e1b7f04d51aafdf222c8b15771 P 10090ffadd054a31a2df225c9fd3b846: stopping tablet replica
I20260812 06:18:05.655494 27629 raft_consensus.cc:2243] T a18e75e1b7f04d51aafdf222c8b15771 P 10090ffadd054a31a2df225c9fd3b846 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:05.655717 27629 raft_consensus.cc:2272] T a18e75e1b7f04d51aafdf222c8b15771 P 10090ffadd054a31a2df225c9fd3b846 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:05.669476 27629 tablet_server.cc:196] TabletServer@127.26.251.65:0 shutdown complete.
I20260812 06:18:05.679023 27629 master.cc:562] Master@127.26.251.126:40905 shutting down...
I20260812 06:18:05.682420 27629 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 43c94848213d473f8c401a911fd1b712 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:05.682629 27629 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 43c94848213d473f8c401a911fd1b712 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:05.682714 27629 tablet_replica.cc:333] T 00000000000000000000000000000000 P 43c94848213d473f8c401a911fd1b712: stopping tablet replica
I20260812 06:18:05.695266 27629 master.cc:584] Master@127.26.251.126:40905 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5406 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10725 ms total)

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