[==========] 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:20:25.290531 12225 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.11.240.126:34993
I20260812 06:20:25.291800 12225 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:20:25.292459 12225 file_cache.cc:504] Constructed file cache file cache with capacity 419430
I20260812 06:20:25.300223 12225 server_base.cc:1061] running on GCE node
W20260812 06:20:25.300328 12235 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:20:25.300235 12232 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:25.300467 12233 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:20:25.301119 12225 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:25.301252 12225 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:20:25.301370 12225 hybrid_clock.cc:648] HybridClock initialized: now 1786515625301297 us; error 0 us; skew 500 ppm
I20260812 06:20:25.303670 12225 webserver.cc:533] Webserver started at http://127.11.240.126:40931/ using document root <none> and password file <none>
I20260812 06:20:25.304279 12225 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:25.304375 12225 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:25.304634 12225 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:25.306425 12225 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625276931-12225-0/minicluster-data/master-0-root/instance:
uuid: "35303195bdb846489d8b2710d8c08fe5"
format_stamp: "Formatted at 2026-08-12 06:20:25 on dist-test-slave-drl0"
I20260812 06:20:25.310151 12225 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.006s	sys 0.000s
I20260812 06:20:25.312518 12243 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:20:25.313635 12225 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:20:25.313792 12225 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625276931-12225-0/minicluster-data/master-0-root
uuid: "35303195bdb846489d8b2710d8c08fe5"
format_stamp: "Formatted at 2026-08-12 06:20:25 on dist-test-slave-drl0"
I20260812 06:20:25.313918 12225 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625276931-12225-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625276931-12225-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625276931-12225-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:20:25.338218 12225 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:25.339027 12225 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:20:25.339217 12225 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:25.347078 12225 rpc_server.cc:307] RPC server started. Bound to: 127.11.240.126:34993
I20260812 06:20:25.347138 12325 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.11.240.126:34993 every 8 connection(s)
I20260812 06:20:25.349583 12326 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:20:25.355082 12326 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 35303195bdb846489d8b2710d8c08fe5: Bootstrap starting.
I20260812 06:20:25.357461 12326 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 35303195bdb846489d8b2710d8c08fe5: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:25.358320 12326 log.cc:826] T 00000000000000000000000000000000 P 35303195bdb846489d8b2710d8c08fe5: Log is configured to *not* fsync() on all Append() calls
I20260812 06:20:25.360380 12326 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 35303195bdb846489d8b2710d8c08fe5: No bootstrap required, opened a new log
I20260812 06:20:25.363236 12326 raft_consensus.cc:359] T 00000000000000000000000000000000 P 35303195bdb846489d8b2710d8c08fe5 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "35303195bdb846489d8b2710d8c08fe5" member_type: VOTER }
I20260812 06:20:25.363413 12326 raft_consensus.cc:385] T 00000000000000000000000000000000 P 35303195bdb846489d8b2710d8c08fe5 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:25.363463 12326 raft_consensus.cc:740] T 00000000000000000000000000000000 P 35303195bdb846489d8b2710d8c08fe5 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 35303195bdb846489d8b2710d8c08fe5, State: Initialized, Role: FOLLOWER
I20260812 06:20:25.364102 12326 consensus_queue.cc:260] T 00000000000000000000000000000000 P 35303195bdb846489d8b2710d8c08fe5 [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: "35303195bdb846489d8b2710d8c08fe5" member_type: VOTER }
I20260812 06:20:25.364251 12326 raft_consensus.cc:399] T 00000000000000000000000000000000 P 35303195bdb846489d8b2710d8c08fe5 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:25.364301 12326 raft_consensus.cc:493] T 00000000000000000000000000000000 P 35303195bdb846489d8b2710d8c08fe5 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:25.364396 12326 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 35303195bdb846489d8b2710d8c08fe5 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:25.365135 12326 raft_consensus.cc:515] T 00000000000000000000000000000000 P 35303195bdb846489d8b2710d8c08fe5 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "35303195bdb846489d8b2710d8c08fe5" member_type: VOTER }
I20260812 06:20:25.365549 12326 leader_election.cc:304] T 00000000000000000000000000000000 P 35303195bdb846489d8b2710d8c08fe5 [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: 35303195bdb846489d8b2710d8c08fe5; no voters: 
I20260812 06:20:25.365818 12326 leader_election.cc:290] T 00000000000000000000000000000000 P 35303195bdb846489d8b2710d8c08fe5 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:25.366005 12329 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 35303195bdb846489d8b2710d8c08fe5 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:25.366276 12329 raft_consensus.cc:697] T 00000000000000000000000000000000 P 35303195bdb846489d8b2710d8c08fe5 [term 1 LEADER]: Becoming Leader. State: Replica: 35303195bdb846489d8b2710d8c08fe5, State: Running, Role: LEADER
I20260812 06:20:25.366737 12329 consensus_queue.cc:237] T 00000000000000000000000000000000 P 35303195bdb846489d8b2710d8c08fe5 [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: "35303195bdb846489d8b2710d8c08fe5" member_type: VOTER }
I20260812 06:20:25.366865 12326 sys_catalog.cc:565] T 00000000000000000000000000000000 P 35303195bdb846489d8b2710d8c08fe5 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:25.368921 12331 sys_catalog.cc:455] T 00000000000000000000000000000000 P 35303195bdb846489d8b2710d8c08fe5 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "35303195bdb846489d8b2710d8c08fe5" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "35303195bdb846489d8b2710d8c08fe5" member_type: VOTER } }
I20260812 06:20:25.369035 12331 sys_catalog.cc:458] T 00000000000000000000000000000000 P 35303195bdb846489d8b2710d8c08fe5 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:25.369246 12332 sys_catalog.cc:455] T 00000000000000000000000000000000 P 35303195bdb846489d8b2710d8c08fe5 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 35303195bdb846489d8b2710d8c08fe5. Latest consensus state: current_term: 1 leader_uuid: "35303195bdb846489d8b2710d8c08fe5" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "35303195bdb846489d8b2710d8c08fe5" member_type: VOTER } }
I20260812 06:20:25.369326 12332 sys_catalog.cc:458] T 00000000000000000000000000000000 P 35303195bdb846489d8b2710d8c08fe5 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:25.369421 12225 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
W20260812 06:20:25.371495 12350 catalog_manager.cc:1594] T 00000000000000000000000000000000 P 35303195bdb846489d8b2710d8c08fe5: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:20:25.371580 12350 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:20:25.371665 12349 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:25.372413 12349 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:25.377743 12349 catalog_manager.cc:1383] Generated new cluster ID: 8bde3f5c9f1b4ab09e945ebf292568eb
I20260812 06:20:25.377822 12349 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:25.400589 12349 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:25.401541 12349 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:25.409230 12349 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 35303195bdb846489d8b2710d8c08fe5: Generated new TSK 0
I20260812 06:20:25.410130 12349 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:25.435247 12225 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:25.439062 12359 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:20:25.439227 12225 server_base.cc:1061] running on GCE node
W20260812 06:20:25.439220 12365 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:20:25.439419 12362 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:20:25.439677 12225 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:25.439721 12225 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:20:25.439738 12225 hybrid_clock.cc:648] HybridClock initialized: now 1786515625439738 us; error 0 us; skew 500 ppm
I20260812 06:20:25.440671 12225 webserver.cc:533] Webserver started at http://127.11.240.65:38815/ using document root <none> and password file <none>
I20260812 06:20:25.440865 12225 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:25.440915 12225 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:25.441035 12225 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:25.441457 12225 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625276931-12225-0/minicluster-data/ts-0-root/instance:
uuid: "3adf10b27bad47ca95942ca0049a2bb7"
format_stamp: "Formatted at 2026-08-12 06:20:25 on dist-test-slave-drl0"
I20260812 06:20:25.443037 12225 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:20:25.444099 12372 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:20:25.444394 12225 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:25.444466 12225 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625276931-12225-0/minicluster-data/ts-0-root
uuid: "3adf10b27bad47ca95942ca0049a2bb7"
format_stamp: "Formatted at 2026-08-12 06:20:25 on dist-test-slave-drl0"
I20260812 06:20:25.444553 12225 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625276931-12225-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625276931-12225-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625276931-12225-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:20:25.463191 12225 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:25.463680 12225 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:25.464241 12225 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:25.465083 12225 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:25.465132 12225 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:25.465204 12225 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:25.465245 12225 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:25.472499 12225 rpc_server.cc:307] RPC server started. Bound to: 127.11.240.65:39575
I20260812 06:20:25.472555 12458 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.11.240.65:39575 every 8 connection(s)
I20260812 06:20:25.484653 12462 heartbeater.cc:344] Connected to a master server at 127.11.240.126:34993
I20260812 06:20:25.484915 12462 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:25.485404 12462 heartbeater.cc:507] Master 127.11.240.126:34993 requested a full tablet report, sending...
I20260812 06:20:25.486977 12266 ts_manager.cc:194] Registered new tserver with Master: 3adf10b27bad47ca95942ca0049a2bb7 (127.11.240.65:39575)
I20260812 06:20:25.487108 12225 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.013918953s
I20260812 06:20:25.488502 12266 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:46498
I20260812 06:20:25.499948 12266 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:46514:
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:20:25.517421 12411 tablet_service.cc:1511] Processing CreateTablet for tablet 74381d5e18094baead0c6fc8dc8fe0f2 (DEFAULT_TABLE table=heavy-update-compaction-test [id=48b19990e60d41d5a28b6425469cb35a]), partition=
I20260812 06:20:25.518038 12411 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 74381d5e18094baead0c6fc8dc8fe0f2. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:25.521335 12482 tablet_bootstrap.cc:492] T 74381d5e18094baead0c6fc8dc8fe0f2 P 3adf10b27bad47ca95942ca0049a2bb7: Bootstrap starting.
I20260812 06:20:25.522323 12482 tablet_bootstrap.cc:654] T 74381d5e18094baead0c6fc8dc8fe0f2 P 3adf10b27bad47ca95942ca0049a2bb7: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:25.523480 12482 tablet_bootstrap.cc:492] T 74381d5e18094baead0c6fc8dc8fe0f2 P 3adf10b27bad47ca95942ca0049a2bb7: No bootstrap required, opened a new log
I20260812 06:20:25.523568 12482 ts_tablet_manager.cc:1403] T 74381d5e18094baead0c6fc8dc8fe0f2 P 3adf10b27bad47ca95942ca0049a2bb7: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:20:25.524039 12482 raft_consensus.cc:359] T 74381d5e18094baead0c6fc8dc8fe0f2 P 3adf10b27bad47ca95942ca0049a2bb7 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3adf10b27bad47ca95942ca0049a2bb7" member_type: VOTER last_known_addr { host: "127.11.240.65" port: 39575 } }
I20260812 06:20:25.524327 12482 raft_consensus.cc:385] T 74381d5e18094baead0c6fc8dc8fe0f2 P 3adf10b27bad47ca95942ca0049a2bb7 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:25.524401 12482 raft_consensus.cc:740] T 74381d5e18094baead0c6fc8dc8fe0f2 P 3adf10b27bad47ca95942ca0049a2bb7 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 3adf10b27bad47ca95942ca0049a2bb7, State: Initialized, Role: FOLLOWER
I20260812 06:20:25.524567 12482 consensus_queue.cc:260] T 74381d5e18094baead0c6fc8dc8fe0f2 P 3adf10b27bad47ca95942ca0049a2bb7 [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: "3adf10b27bad47ca95942ca0049a2bb7" member_type: VOTER last_known_addr { host: "127.11.240.65" port: 39575 } }
I20260812 06:20:25.524686 12482 raft_consensus.cc:399] T 74381d5e18094baead0c6fc8dc8fe0f2 P 3adf10b27bad47ca95942ca0049a2bb7 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:25.524744 12482 raft_consensus.cc:493] T 74381d5e18094baead0c6fc8dc8fe0f2 P 3adf10b27bad47ca95942ca0049a2bb7 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:25.524804 12482 raft_consensus.cc:3060] T 74381d5e18094baead0c6fc8dc8fe0f2 P 3adf10b27bad47ca95942ca0049a2bb7 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:25.525642 12482 raft_consensus.cc:515] T 74381d5e18094baead0c6fc8dc8fe0f2 P 3adf10b27bad47ca95942ca0049a2bb7 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3adf10b27bad47ca95942ca0049a2bb7" member_type: VOTER last_known_addr { host: "127.11.240.65" port: 39575 } }
I20260812 06:20:25.525806 12482 leader_election.cc:304] T 74381d5e18094baead0c6fc8dc8fe0f2 P 3adf10b27bad47ca95942ca0049a2bb7 [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: 3adf10b27bad47ca95942ca0049a2bb7; no voters: 
I20260812 06:20:25.526038 12482 leader_election.cc:290] T 74381d5e18094baead0c6fc8dc8fe0f2 P 3adf10b27bad47ca95942ca0049a2bb7 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:25.526144 12484 raft_consensus.cc:2804] T 74381d5e18094baead0c6fc8dc8fe0f2 P 3adf10b27bad47ca95942ca0049a2bb7 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:25.526335 12484 raft_consensus.cc:697] T 74381d5e18094baead0c6fc8dc8fe0f2 P 3adf10b27bad47ca95942ca0049a2bb7 [term 1 LEADER]: Becoming Leader. State: Replica: 3adf10b27bad47ca95942ca0049a2bb7, State: Running, Role: LEADER
I20260812 06:20:25.526467 12482 ts_tablet_manager.cc:1434] T 74381d5e18094baead0c6fc8dc8fe0f2 P 3adf10b27bad47ca95942ca0049a2bb7: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:20:25.526543 12484 consensus_queue.cc:237] T 74381d5e18094baead0c6fc8dc8fe0f2 P 3adf10b27bad47ca95942ca0049a2bb7 [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: "3adf10b27bad47ca95942ca0049a2bb7" member_type: VOTER last_known_addr { host: "127.11.240.65" port: 39575 } }
I20260812 06:20:25.526795 12462 heartbeater.cc:499] Master 127.11.240.126:34993 was elected leader, sending a full tablet report...
I20260812 06:20:25.529788 12266 catalog_manager.cc:5719] T 74381d5e18094baead0c6fc8dc8fe0f2 P 3adf10b27bad47ca95942ca0049a2bb7 reported cstate change: term changed from 0 to 1, leader changed from <none> to 3adf10b27bad47ca95942ca0049a2bb7 (127.11.240.65). New cstate: current_term: 1 leader_uuid: "3adf10b27bad47ca95942ca0049a2bb7" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3adf10b27bad47ca95942ca0049a2bb7" member_type: VOTER last_known_addr { host: "127.11.240.65" port: 39575 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:25.602106 12225 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.063s	user 0.021s	sys 0.007s
I20260812 06:20:25.723706 12463 maintenance_manager.cc:419] P 3adf10b27bad47ca95942ca0049a2bb7: Scheduling FlushMRSOp(74381d5e18094baead0c6fc8dc8fe0f2): perf score=15.086190
I20260812 06:20:25.903566 12378 maintenance_manager.cc:643] P 3adf10b27bad47ca95942ca0049a2bb7: FlushMRSOp(74381d5e18094baead0c6fc8dc8fe0f2) complete. Timing: real 0.179s	user 0.130s	sys 0.049s Metrics: {"bytes_written":12307491,"cfile_init":1,"compiler_manager_pool.queue_time_us":274,"delete_count":0,"dirs.queue_time_us":47,"dirs.run_cpu_time_us":194,"dirs.run_wall_time_us":901,"drs_written":1,"lbm_read_time_us":73,"lbm_reads_lt_1ms":4,"lbm_write_time_us":45548,"lbm_writes_lt_1ms":657,"peak_mem_usage":0,"reinsert_count":0,"rows_written":103,"thread_start_us":180,"threads_started":1,"update_count":1500}
I20260812 06:20:25.904898 12463 maintenance_manager.cc:419] P 3adf10b27bad47ca95942ca0049a2bb7: Scheduling LogGCOp(74381d5e18094baead0c6fc8dc8fe0f2): free 8725963 bytes of WAL
I20260812 06:20:25.905233 12378 log_reader.cc:385] T 74381d5e18094baead0c6fc8dc8fe0f2: removed 1 log segments from log reader
I20260812 06:20:25.905284 12378 log.cc:1079] T 74381d5e18094baead0c6fc8dc8fe0f2 P 3adf10b27bad47ca95942ca0049a2bb7: Deleting log segment in path: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625276931-12225-0/minicluster-data/ts-0-root/wals/74381d5e18094baead0c6fc8dc8fe0f2/wal-000000001 (ops 1-6)
I20260812 06:20:25.908128 12378 maintenance_manager.cc:643] P 3adf10b27bad47ca95942ca0049a2bb7: LogGCOp(74381d5e18094baead0c6fc8dc8fe0f2) complete. Timing: real 0.003s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:20:25.908486 12463 maintenance_manager.cc:419] P 3adf10b27bad47ca95942ca0049a2bb7: Scheduling UndoDeltaBlockGCOp(74381d5e18094baead0c6fc8dc8fe0f2): 12308960 bytes on disk
I20260812 06:20:25.909116 12378 maintenance_manager.cc:643] P 3adf10b27bad47ca95942ca0049a2bb7: UndoDeltaBlockGCOp(74381d5e18094baead0c6fc8dc8fe0f2) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":77,"lbm_reads_lt_1ms":4}
I20260812 06:20:25.909559 12463 maintenance_manager.cc:419] P 3adf10b27bad47ca95942ca0049a2bb7: Scheduling FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2): perf score=2.188937
I20260812 06:20:25.940907 12378 maintenance_manager.cc:643] P 3adf10b27bad47ca95942ca0049a2bb7: FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2) complete. Timing: real 0.031s	user 0.006s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6230,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:25.941561 12463 maintenance_manager.cc:419] P 3adf10b27bad47ca95942ca0049a2bb7: Scheduling FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2): perf score=2.188937
I20260812 06:20:25.959017 12378 maintenance_manager.cc:643] P 3adf10b27bad47ca95942ca0049a2bb7: FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2) complete. Timing: real 0.017s	user 0.010s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6702,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:25.959645 12463 maintenance_manager.cc:419] P 3adf10b27bad47ca95942ca0049a2bb7: Scheduling MajorDeltaCompactionOp(74381d5e18094baead0c6fc8dc8fe0f2): perf score=1.000000
I20260812 06:20:26.145648 12378 maintenance_manager.cc:643] P 3adf10b27bad47ca95942ca0049a2bb7: MajorDeltaCompactionOp(74381d5e18094baead0c6fc8dc8fe0f2) complete. Timing: real 0.186s	user 0.137s	sys 0.044s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24733844,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":859,"lbm_read_time_us":12823,"lbm_reads_lt_1ms":569,"lbm_write_time_us":34794,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":353,"threads_started":5,"update_count":2500}
I20260812 06:20:26.146380 12463 maintenance_manager.cc:419] P 3adf10b27bad47ca95942ca0049a2bb7: Scheduling FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2): perf score=10.126437
I20260812 06:20:26.190109 12378 maintenance_manager.cc:643] P 3adf10b27bad47ca95942ca0049a2bb7: FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2) complete. Timing: real 0.043s	user 0.032s	sys 0.008s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":18446,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:26.190712 12463 maintenance_manager.cc:419] P 3adf10b27bad47ca95942ca0049a2bb7: Scheduling FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2): perf score=2.188937
I20260812 06:20:26.216053 12378 maintenance_manager.cc:643] P 3adf10b27bad47ca95942ca0049a2bb7: FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2) complete. Timing: real 0.025s	user 0.010s	sys 0.010s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":8333,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:26.216897 12463 maintenance_manager.cc:419] P 3adf10b27bad47ca95942ca0049a2bb7: Scheduling MajorDeltaCompactionOp(74381d5e18094baead0c6fc8dc8fe0f2): perf score=1.000000
I20260812 06:20:26.371117 12378 maintenance_manager.cc:643] P 3adf10b27bad47ca95942ca0049a2bb7: MajorDeltaCompactionOp(74381d5e18094baead0c6fc8dc8fe0f2) complete. Timing: real 0.154s	user 0.100s	sys 0.052s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631310,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":985,"lbm_read_time_us":10777,"lbm_reads_lt_1ms":464,"lbm_write_time_us":31967,"lbm_writes_lt_1ms":443,"mutex_wait_us":2,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:20:26.372201 12463 maintenance_manager.cc:419] P 3adf10b27bad47ca95942ca0049a2bb7: Scheduling FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2): perf score=11.118625
I20260812 06:20:26.415560 12378 maintenance_manager.cc:643] P 3adf10b27bad47ca95942ca0049a2bb7: FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2) complete. Timing: real 0.043s	user 0.030s	sys 0.012s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":18531,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:26.416081 12463 maintenance_manager.cc:419] P 3adf10b27bad47ca95942ca0049a2bb7: Scheduling FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2): perf score=2.188937
I20260812 06:20:26.441094 12378 maintenance_manager.cc:643] P 3adf10b27bad47ca95942ca0049a2bb7: FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2) complete. Timing: real 0.025s	user 0.010s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6839,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:26.441545 12463 maintenance_manager.cc:419] P 3adf10b27bad47ca95942ca0049a2bb7: Scheduling FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2): perf score=2.188937
I20260812 06:20:26.452099 12378 maintenance_manager.cc:643] P 3adf10b27bad47ca95942ca0049a2bb7: FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2) complete. Timing: real 0.010s	user 0.000s	sys 0.009s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3809,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:26.452549 12463 maintenance_manager.cc:419] P 3adf10b27bad47ca95942ca0049a2bb7: Scheduling MajorDeltaCompactionOp(74381d5e18094baead0c6fc8dc8fe0f2): perf score=1.000000
I20260812 06:20:26.636044 12378 maintenance_manager.cc:643] P 3adf10b27bad47ca95942ca0049a2bb7: MajorDeltaCompactionOp(74381d5e18094baead0c6fc8dc8fe0f2) complete. Timing: real 0.183s	user 0.124s	sys 0.049s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24733835,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1114,"lbm_read_time_us":12951,"lbm_reads_lt_1ms":573,"lbm_write_time_us":30931,"lbm_writes_lt_1ms":543,"mutex_wait_us":375,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":22016,"update_count":2500}
I20260812 06:20:26.636768 12463 maintenance_manager.cc:419] P 3adf10b27bad47ca95942ca0049a2bb7: Scheduling FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2): perf score=14.095187
I20260812 06:20:26.695616 12378 maintenance_manager.cc:643] P 3adf10b27bad47ca95942ca0049a2bb7: FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2) complete. Timing: real 0.059s	user 0.027s	sys 0.024s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":23193,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:26.696189 12463 maintenance_manager.cc:419] P 3adf10b27bad47ca95942ca0049a2bb7: Scheduling MajorDeltaCompactionOp(74381d5e18094baead0c6fc8dc8fe0f2): perf score=1.000000
I20260812 06:20:26.869272 12378 maintenance_manager.cc:643] P 3adf10b27bad47ca95942ca0049a2bb7: MajorDeltaCompactionOp(74381d5e18094baead0c6fc8dc8fe0f2) complete. Timing: real 0.173s	user 0.110s	sys 0.058s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20631191,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":564,"lbm_read_time_us":12043,"lbm_reads_lt_1ms":463,"lbm_write_time_us":29090,"lbm_writes_lt_1ms":443,"mutex_wait_us":282,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7040,"update_count":2000}
I20260812 06:20:26.869783 12463 maintenance_manager.cc:419] P 3adf10b27bad47ca95942ca0049a2bb7: Scheduling FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2): perf score=14.095187
I20260812 06:20:26.932350 12378 maintenance_manager.cc:643] P 3adf10b27bad47ca95942ca0049a2bb7: FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2) complete. Timing: real 0.062s	user 0.036s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":25079,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:26.932979 12463 maintenance_manager.cc:419] P 3adf10b27bad47ca95942ca0049a2bb7: Scheduling FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2): perf score=2.188937
I20260812 06:20:26.947343 12378 maintenance_manager.cc:643] P 3adf10b27bad47ca95942ca0049a2bb7: FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2) complete. Timing: real 0.014s	user 0.002s	sys 0.012s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5776,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:26.948256 12463 maintenance_manager.cc:419] P 3adf10b27bad47ca95942ca0049a2bb7: Scheduling MajorDeltaCompactionOp(74381d5e18094baead0c6fc8dc8fe0f2): perf score=1.000000
I20260812 06:20:27.152086 12378 maintenance_manager.cc:643] P 3adf10b27bad47ca95942ca0049a2bb7: MajorDeltaCompactionOp(74381d5e18094baead0c6fc8dc8fe0f2) complete. Timing: real 0.204s	user 0.123s	sys 0.072s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733722,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1503,"lbm_read_time_us":12721,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34650,"lbm_writes_lt_1ms":543,"mutex_wait_us":458,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2432,"update_count":2500}
I20260812 06:20:27.153051 12463 maintenance_manager.cc:419] P 3adf10b27bad47ca95942ca0049a2bb7: Scheduling FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2): perf score=11.118625
I20260812 06:20:27.188547 12378 maintenance_manager.cc:643] P 3adf10b27bad47ca95942ca0049a2bb7: FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2) complete. Timing: real 0.035s	user 0.018s	sys 0.015s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":16212,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:27.189275 12463 maintenance_manager.cc:419] P 3adf10b27bad47ca95942ca0049a2bb7: Scheduling FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2): perf score=2.188937
I20260812 06:20:27.207893 12378 maintenance_manager.cc:643] P 3adf10b27bad47ca95942ca0049a2bb7: FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2) complete. Timing: real 0.018s	user 0.011s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6454,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:27.208406 12463 maintenance_manager.cc:419] P 3adf10b27bad47ca95942ca0049a2bb7: Scheduling FlushMRSOp(74381d5e18094baead0c6fc8dc8fe0f2): perf score=1.000000
I20260812 06:20:27.251422 12378 maintenance_manager.cc:643] P 3adf10b27bad47ca95942ca0049a2bb7: FlushMRSOp(74381d5e18094baead0c6fc8dc8fe0f2) complete. Timing: real 0.043s	user 0.024s	sys 0.003s Metrics: {"bytes_written":1152509,"cfile_init":1,"dirs.queue_time_us":69,"dirs.run_cpu_time_us":244,"dirs.run_wall_time_us":1478,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1622,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:20:27.252554 12463 maintenance_manager.cc:419] P 3adf10b27bad47ca95942ca0049a2bb7: Scheduling UndoDeltaBlockGCOp(74381d5e18094baead0c6fc8dc8fe0f2): 447 bytes on disk
I20260812 06:20:27.253105 12378 maintenance_manager.cc:643] P 3adf10b27bad47ca95942ca0049a2bb7: UndoDeltaBlockGCOp(74381d5e18094baead0c6fc8dc8fe0f2) 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:20:27.253612 12463 maintenance_manager.cc:419] P 3adf10b27bad47ca95942ca0049a2bb7: Scheduling FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2): perf score=3.181125
I20260812 06:20:27.278860 12378 maintenance_manager.cc:643] P 3adf10b27bad47ca95942ca0049a2bb7: FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2) complete. Timing: real 0.025s	user 0.009s	sys 0.012s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4999,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:27.279507 12463 maintenance_manager.cc:419] P 3adf10b27bad47ca95942ca0049a2bb7: Scheduling LogGCOp(74381d5e18094baead0c6fc8dc8fe0f2): free 124257229 bytes of WAL
I20260812 06:20:27.279747 12378 log_reader.cc:385] T 74381d5e18094baead0c6fc8dc8fe0f2: removed 12 log segments from log reader
I20260812 06:20:27.279808 12378 log.cc:1079] T 74381d5e18094baead0c6fc8dc8fe0f2 P 3adf10b27bad47ca95942ca0049a2bb7: Deleting log segment in path: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625276931-12225-0/minicluster-data/ts-0-root/wals/74381d5e18094baead0c6fc8dc8fe0f2/wal-000000002 (ops 7-11)
I20260812 06:20:27.279865 12378 log.cc:1079] T 74381d5e18094baead0c6fc8dc8fe0f2 P 3adf10b27bad47ca95942ca0049a2bb7: Deleting log segment in path: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625276931-12225-0/minicluster-data/ts-0-root/wals/74381d5e18094baead0c6fc8dc8fe0f2/wal-000000003 (ops 12-16)
I20260812 06:20:27.279925 12378 log.cc:1079] T 74381d5e18094baead0c6fc8dc8fe0f2 P 3adf10b27bad47ca95942ca0049a2bb7: Deleting log segment in path: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625276931-12225-0/minicluster-data/ts-0-root/wals/74381d5e18094baead0c6fc8dc8fe0f2/wal-000000004 (ops 17-20)
I20260812 06:20:27.279968 12378 log.cc:1079] T 74381d5e18094baead0c6fc8dc8fe0f2 P 3adf10b27bad47ca95942ca0049a2bb7: Deleting log segment in path: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625276931-12225-0/minicluster-data/ts-0-root/wals/74381d5e18094baead0c6fc8dc8fe0f2/wal-000000005 (ops 21-25)
I20260812 06:20:27.279999 12378 log.cc:1079] T 74381d5e18094baead0c6fc8dc8fe0f2 P 3adf10b27bad47ca95942ca0049a2bb7: Deleting log segment in path: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625276931-12225-0/minicluster-data/ts-0-root/wals/74381d5e18094baead0c6fc8dc8fe0f2/wal-000000006 (ops 26-30)
I20260812 06:20:27.280030 12378 log.cc:1079] T 74381d5e18094baead0c6fc8dc8fe0f2 P 3adf10b27bad47ca95942ca0049a2bb7: Deleting log segment in path: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625276931-12225-0/minicluster-data/ts-0-root/wals/74381d5e18094baead0c6fc8dc8fe0f2/wal-000000007 (ops 31-35)
I20260812 06:20:27.280068 12378 log.cc:1079] T 74381d5e18094baead0c6fc8dc8fe0f2 P 3adf10b27bad47ca95942ca0049a2bb7: Deleting log segment in path: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625276931-12225-0/minicluster-data/ts-0-root/wals/74381d5e18094baead0c6fc8dc8fe0f2/wal-000000008 (ops 36-40)
I20260812 06:20:27.280107 12378 log.cc:1079] T 74381d5e18094baead0c6fc8dc8fe0f2 P 3adf10b27bad47ca95942ca0049a2bb7: Deleting log segment in path: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625276931-12225-0/minicluster-data/ts-0-root/wals/74381d5e18094baead0c6fc8dc8fe0f2/wal-000000009 (ops 41-44)
I20260812 06:20:27.280143 12378 log.cc:1079] T 74381d5e18094baead0c6fc8dc8fe0f2 P 3adf10b27bad47ca95942ca0049a2bb7: Deleting log segment in path: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625276931-12225-0/minicluster-data/ts-0-root/wals/74381d5e18094baead0c6fc8dc8fe0f2/wal-000000010 (ops 45-49)
I20260812 06:20:27.280179 12378 log.cc:1079] T 74381d5e18094baead0c6fc8dc8fe0f2 P 3adf10b27bad47ca95942ca0049a2bb7: Deleting log segment in path: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625276931-12225-0/minicluster-data/ts-0-root/wals/74381d5e18094baead0c6fc8dc8fe0f2/wal-000000011 (ops 50-55)
I20260812 06:20:27.280216 12378 log.cc:1079] T 74381d5e18094baead0c6fc8dc8fe0f2 P 3adf10b27bad47ca95942ca0049a2bb7: Deleting log segment in path: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625276931-12225-0/minicluster-data/ts-0-root/wals/74381d5e18094baead0c6fc8dc8fe0f2/wal-000000012 (ops 56-60)
I20260812 06:20:27.280252 12378 log.cc:1079] T 74381d5e18094baead0c6fc8dc8fe0f2 P 3adf10b27bad47ca95942ca0049a2bb7: Deleting log segment in path: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625276931-12225-0/minicluster-data/ts-0-root/wals/74381d5e18094baead0c6fc8dc8fe0f2/wal-000000013 (ops 61-65)
I20260812 06:20:27.309291 12378 maintenance_manager.cc:643] P 3adf10b27bad47ca95942ca0049a2bb7: LogGCOp(74381d5e18094baead0c6fc8dc8fe0f2) complete. Timing: real 0.030s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:20:27.309799 12463 maintenance_manager.cc:419] P 3adf10b27bad47ca95942ca0049a2bb7: Scheduling FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2): perf score=2.188937
I20260812 06:20:27.326336 12378 maintenance_manager.cc:643] P 3adf10b27bad47ca95942ca0049a2bb7: FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2) complete. Timing: real 0.016s	user 0.014s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6061,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:27.326849 12463 maintenance_manager.cc:419] P 3adf10b27bad47ca95942ca0049a2bb7: Scheduling MajorDeltaCompactionOp(74381d5e18094baead0c6fc8dc8fe0f2): perf score=1.000000
I20260812 06:20:27.536077 12378 maintenance_manager.cc:643] P 3adf10b27bad47ca95942ca0049a2bb7: MajorDeltaCompactionOp(74381d5e18094baead0c6fc8dc8fe0f2) complete. Timing: real 0.209s	user 0.136s	sys 0.072s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836353,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":566,"lbm_read_time_us":15526,"lbm_reads_lt_1ms":670,"lbm_write_time_us":35435,"lbm_writes_lt_1ms":643,"mutex_wait_us":31,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":4992,"thread_start_us":85,"threads_started":1,"update_count":3000}
I20260812 06:20:27.537384 12463 maintenance_manager.cc:419] P 3adf10b27bad47ca95942ca0049a2bb7: Scheduling FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2): perf score=14.095187
I20260812 06:20:27.600172 12378 maintenance_manager.cc:643] P 3adf10b27bad47ca95942ca0049a2bb7: FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2) complete. Timing: real 0.063s	user 0.034s	sys 0.027s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22020,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:27.600657 12463 maintenance_manager.cc:419] P 3adf10b27bad47ca95942ca0049a2bb7: Scheduling FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2): perf score=2.188937
I20260812 06:20:27.613045 12378 maintenance_manager.cc:643] P 3adf10b27bad47ca95942ca0049a2bb7: FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4480,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:27.616889 12463 maintenance_manager.cc:419] P 3adf10b27bad47ca95942ca0049a2bb7: Scheduling MajorDeltaCompactionOp(74381d5e18094baead0c6fc8dc8fe0f2): perf score=1.000000
I20260812 06:20:27.810026 12378 maintenance_manager.cc:643] P 3adf10b27bad47ca95942ca0049a2bb7: MajorDeltaCompactionOp(74381d5e18094baead0c6fc8dc8fe0f2) complete. Timing: real 0.193s	user 0.117s	sys 0.068s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733724,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"lbm_read_time_us":14672,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31952,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:20:27.810640 12463 maintenance_manager.cc:419] P 3adf10b27bad47ca95942ca0049a2bb7: Scheduling FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2): perf score=14.095187
I20260812 06:20:27.870596 12378 maintenance_manager.cc:643] P 3adf10b27bad47ca95942ca0049a2bb7: FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2) complete. Timing: real 0.059s	user 0.036s	sys 0.020s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":25685,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:27.871150 12463 maintenance_manager.cc:419] P 3adf10b27bad47ca95942ca0049a2bb7: Scheduling FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2): perf score=2.188937
I20260812 06:20:27.883390 12378 maintenance_manager.cc:643] P 3adf10b27bad47ca95942ca0049a2bb7: FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4476,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:27.883873 12463 maintenance_manager.cc:419] P 3adf10b27bad47ca95942ca0049a2bb7: Scheduling MajorDeltaCompactionOp(74381d5e18094baead0c6fc8dc8fe0f2): perf score=1.000000
I20260812 06:20:28.091027 12378 maintenance_manager.cc:643] P 3adf10b27bad47ca95942ca0049a2bb7: MajorDeltaCompactionOp(74381d5e18094baead0c6fc8dc8fe0f2) complete. Timing: real 0.207s	user 0.129s	sys 0.073s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733725,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1818,"lbm_read_time_us":12641,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33572,"lbm_writes_lt_1ms":543,"mutex_wait_us":22,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":428544,"update_count":2500}
I20260812 06:20:28.092088 12463 maintenance_manager.cc:419] P 3adf10b27bad47ca95942ca0049a2bb7: Scheduling FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2): perf score=11.118625
I20260812 06:20:28.142154 12378 maintenance_manager.cc:643] P 3adf10b27bad47ca95942ca0049a2bb7: FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2) complete. Timing: real 0.050s	user 0.026s	sys 0.020s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":25427,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":311,"reinsert_count":0,"update_count":1550}
I20260812 06:20:28.143170 12463 maintenance_manager.cc:419] P 3adf10b27bad47ca95942ca0049a2bb7: Scheduling FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2): perf score=2.188937
I20260812 06:20:28.157279 12378 maintenance_manager.cc:643] P 3adf10b27bad47ca95942ca0049a2bb7: FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2) complete. Timing: real 0.014s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5731,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:28.157969 12463 maintenance_manager.cc:419] P 3adf10b27bad47ca95942ca0049a2bb7: Scheduling FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2): perf score=2.188937
I20260812 06:20:28.170608 12378 maintenance_manager.cc:643] P 3adf10b27bad47ca95942ca0049a2bb7: FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2) complete. Timing: real 0.012s	user 0.001s	sys 0.009s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3939,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:28.171432 12463 maintenance_manager.cc:419] P 3adf10b27bad47ca95942ca0049a2bb7: Scheduling MajorDeltaCompactionOp(74381d5e18094baead0c6fc8dc8fe0f2): perf score=1.000000
I20260812 06:20:28.336043 12378 maintenance_manager.cc:643] P 3adf10b27bad47ca95942ca0049a2bb7: MajorDeltaCompactionOp(74381d5e18094baead0c6fc8dc8fe0f2) complete. Timing: real 0.164s	user 0.111s	sys 0.048s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24733834,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":632,"lbm_read_time_us":11484,"lbm_reads_lt_1ms":573,"lbm_write_time_us":33038,"lbm_writes_lt_1ms":543,"mutex_wait_us":145,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":17408,"update_count":2500}
I20260812 06:20:28.336882 12463 maintenance_manager.cc:419] P 3adf10b27bad47ca95942ca0049a2bb7: Scheduling FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2): perf score=11.118625
I20260812 06:20:28.379860 12378 maintenance_manager.cc:643] P 3adf10b27bad47ca95942ca0049a2bb7: FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2) complete. Timing: real 0.043s	user 0.033s	sys 0.008s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":17158,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:28.383438 12463 maintenance_manager.cc:419] P 3adf10b27bad47ca95942ca0049a2bb7: Scheduling FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2): perf score=2.188937
I20260812 06:20:28.400058 12378 maintenance_manager.cc:643] P 3adf10b27bad47ca95942ca0049a2bb7: FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2) complete. Timing: real 0.016s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4510,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:28.400512 12463 maintenance_manager.cc:419] P 3adf10b27bad47ca95942ca0049a2bb7: Scheduling FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2): perf score=2.188937
I20260812 06:20:28.411705 12378 maintenance_manager.cc:643] P 3adf10b27bad47ca95942ca0049a2bb7: FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2) complete. Timing: real 0.011s	user 0.003s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4033,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:28.412379 12463 maintenance_manager.cc:419] P 3adf10b27bad47ca95942ca0049a2bb7: Scheduling MajorDeltaCompactionOp(74381d5e18094baead0c6fc8dc8fe0f2): perf score=1.000000
I20260812 06:20:28.574752 12378 maintenance_manager.cc:643] P 3adf10b27bad47ca95942ca0049a2bb7: MajorDeltaCompactionOp(74381d5e18094baead0c6fc8dc8fe0f2) complete. Timing: real 0.162s	user 0.132s	sys 0.023s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24733835,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":61,"lbm_read_time_us":11397,"lbm_reads_lt_1ms":573,"lbm_write_time_us":32058,"lbm_writes_lt_1ms":543,"mutex_wait_us":3,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3712,"update_count":2500}
I20260812 06:20:28.575623 12463 maintenance_manager.cc:419] P 3adf10b27bad47ca95942ca0049a2bb7: Scheduling FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2): perf score=11.118625
I20260812 06:20:28.613183 12378 maintenance_manager.cc:643] P 3adf10b27bad47ca95942ca0049a2bb7: FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2) complete. Timing: real 0.037s	user 0.014s	sys 0.021s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":16459,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:28.613791 12463 maintenance_manager.cc:419] P 3adf10b27bad47ca95942ca0049a2bb7: Scheduling FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2): perf score=2.188937
I20260812 06:20:28.628384 12378 maintenance_manager.cc:643] P 3adf10b27bad47ca95942ca0049a2bb7: FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2) complete. Timing: real 0.014s	user 0.008s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5331,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:28.628974 12463 maintenance_manager.cc:419] P 3adf10b27bad47ca95942ca0049a2bb7: Scheduling MajorDeltaCompactionOp(74381d5e18094baead0c6fc8dc8fe0f2): perf score=1.000000
I20260812 06:20:28.778157 12378 maintenance_manager.cc:643] P 3adf10b27bad47ca95942ca0049a2bb7: MajorDeltaCompactionOp(74381d5e18094baead0c6fc8dc8fe0f2) complete. Timing: real 0.149s	user 0.104s	sys 0.042s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631303,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":201,"lbm_read_time_us":10057,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28667,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:20:28.779397 12463 maintenance_manager.cc:419] P 3adf10b27bad47ca95942ca0049a2bb7: Scheduling FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2): perf score=10.126437
I20260812 06:20:28.816632 12378 maintenance_manager.cc:643] P 3adf10b27bad47ca95942ca0049a2bb7: FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2) complete. Timing: real 0.037s	user 0.016s	sys 0.017s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14338,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:28.817235 12463 maintenance_manager.cc:419] P 3adf10b27bad47ca95942ca0049a2bb7: Scheduling FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2): perf score=2.188937
I20260812 06:20:28.829113 12378 maintenance_manager.cc:643] P 3adf10b27bad47ca95942ca0049a2bb7: FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4289,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:28.829581 12463 maintenance_manager.cc:419] P 3adf10b27bad47ca95942ca0049a2bb7: Scheduling FlushMRSOp(74381d5e18094baead0c6fc8dc8fe0f2): perf score=1.000000
I20260812 06:20:28.863731 12378 maintenance_manager.cc:643] P 3adf10b27bad47ca95942ca0049a2bb7: FlushMRSOp(74381d5e18094baead0c6fc8dc8fe0f2) complete. Timing: real 0.034s	user 0.031s	sys 0.001s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":62,"dirs.run_cpu_time_us":302,"dirs.run_wall_time_us":1752,"drs_written":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1525,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:20:28.864562 12463 maintenance_manager.cc:419] P 3adf10b27bad47ca95942ca0049a2bb7: Scheduling LogGCOp(74381d5e18094baead0c6fc8dc8fe0f2): free 112692373 bytes of WAL
I20260812 06:20:28.864913 12378 log_reader.cc:385] T 74381d5e18094baead0c6fc8dc8fe0f2: removed 11 log segments from log reader
I20260812 06:20:28.864985 12378 log.cc:1079] T 74381d5e18094baead0c6fc8dc8fe0f2 P 3adf10b27bad47ca95942ca0049a2bb7: Deleting log segment in path: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625276931-12225-0/minicluster-data/ts-0-root/wals/74381d5e18094baead0c6fc8dc8fe0f2/wal-000000014 (ops 66-70)
I20260812 06:20:28.865043 12378 log.cc:1079] T 74381d5e18094baead0c6fc8dc8fe0f2 P 3adf10b27bad47ca95942ca0049a2bb7: Deleting log segment in path: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625276931-12225-0/minicluster-data/ts-0-root/wals/74381d5e18094baead0c6fc8dc8fe0f2/wal-000000015 (ops 71-75)
I20260812 06:20:28.865101 12378 log.cc:1079] T 74381d5e18094baead0c6fc8dc8fe0f2 P 3adf10b27bad47ca95942ca0049a2bb7: Deleting log segment in path: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625276931-12225-0/minicluster-data/ts-0-root/wals/74381d5e18094baead0c6fc8dc8fe0f2/wal-000000016 (ops 76-80)
I20260812 06:20:28.865145 12378 log.cc:1079] T 74381d5e18094baead0c6fc8dc8fe0f2 P 3adf10b27bad47ca95942ca0049a2bb7: Deleting log segment in path: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625276931-12225-0/minicluster-data/ts-0-root/wals/74381d5e18094baead0c6fc8dc8fe0f2/wal-000000017 (ops 81-85)
I20260812 06:20:28.865185 12378 log.cc:1079] T 74381d5e18094baead0c6fc8dc8fe0f2 P 3adf10b27bad47ca95942ca0049a2bb7: Deleting log segment in path: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625276931-12225-0/minicluster-data/ts-0-root/wals/74381d5e18094baead0c6fc8dc8fe0f2/wal-000000018 (ops 86-90)
I20260812 06:20:28.865224 12378 log.cc:1079] T 74381d5e18094baead0c6fc8dc8fe0f2 P 3adf10b27bad47ca95942ca0049a2bb7: Deleting log segment in path: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625276931-12225-0/minicluster-data/ts-0-root/wals/74381d5e18094baead0c6fc8dc8fe0f2/wal-000000019 (ops 91-95)
I20260812 06:20:28.865262 12378 log.cc:1079] T 74381d5e18094baead0c6fc8dc8fe0f2 P 3adf10b27bad47ca95942ca0049a2bb7: Deleting log segment in path: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625276931-12225-0/minicluster-data/ts-0-root/wals/74381d5e18094baead0c6fc8dc8fe0f2/wal-000000020 (ops 96-100)
I20260812 06:20:28.865309 12378 log.cc:1079] T 74381d5e18094baead0c6fc8dc8fe0f2 P 3adf10b27bad47ca95942ca0049a2bb7: Deleting log segment in path: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625276931-12225-0/minicluster-data/ts-0-root/wals/74381d5e18094baead0c6fc8dc8fe0f2/wal-000000021 (ops 101-105)
I20260812 06:20:28.865350 12378 log.cc:1079] T 74381d5e18094baead0c6fc8dc8fe0f2 P 3adf10b27bad47ca95942ca0049a2bb7: Deleting log segment in path: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625276931-12225-0/minicluster-data/ts-0-root/wals/74381d5e18094baead0c6fc8dc8fe0f2/wal-000000022 (ops 106-110)
I20260812 06:20:28.865387 12378 log.cc:1079] T 74381d5e18094baead0c6fc8dc8fe0f2 P 3adf10b27bad47ca95942ca0049a2bb7: Deleting log segment in path: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625276931-12225-0/minicluster-data/ts-0-root/wals/74381d5e18094baead0c6fc8dc8fe0f2/wal-000000023 (ops 111-115)
I20260812 06:20:28.865425 12378 log.cc:1079] T 74381d5e18094baead0c6fc8dc8fe0f2 P 3adf10b27bad47ca95942ca0049a2bb7: Deleting log segment in path: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625276931-12225-0/minicluster-data/ts-0-root/wals/74381d5e18094baead0c6fc8dc8fe0f2/wal-000000024 (ops 116-120)
I20260812 06:20:28.893816 12378 maintenance_manager.cc:643] P 3adf10b27bad47ca95942ca0049a2bb7: LogGCOp(74381d5e18094baead0c6fc8dc8fe0f2) complete. Timing: real 0.029s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:20:28.894345 12463 maintenance_manager.cc:419] P 3adf10b27bad47ca95942ca0049a2bb7: Scheduling UndoDeltaBlockGCOp(74381d5e18094baead0c6fc8dc8fe0f2): 463 bytes on disk
I20260812 06:20:28.894894 12378 maintenance_manager.cc:643] P 3adf10b27bad47ca95942ca0049a2bb7: UndoDeltaBlockGCOp(74381d5e18094baead0c6fc8dc8fe0f2) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":71,"lbm_reads_lt_1ms":4}
I20260812 06:20:28.895784 12463 maintenance_manager.cc:419] P 3adf10b27bad47ca95942ca0049a2bb7: Scheduling FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2): perf score=3.181125
I20260812 06:20:28.915102 12378 maintenance_manager.cc:643] P 3adf10b27bad47ca95942ca0049a2bb7: FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2) complete. Timing: real 0.019s	user 0.018s	sys 0.000s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":7448,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:28.915632 12463 maintenance_manager.cc:419] P 3adf10b27bad47ca95942ca0049a2bb7: Scheduling LogGCOp(74381d5e18094baead0c6fc8dc8fe0f2): free 11564875 bytes of WAL
I20260812 06:20:28.916030 12378 log_reader.cc:385] T 74381d5e18094baead0c6fc8dc8fe0f2: removed 1 log segments from log reader
I20260812 06:20:28.916143 12378 log.cc:1079] T 74381d5e18094baead0c6fc8dc8fe0f2 P 3adf10b27bad47ca95942ca0049a2bb7: Deleting log segment in path: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625276931-12225-0/minicluster-data/ts-0-root/wals/74381d5e18094baead0c6fc8dc8fe0f2/wal-000000025 (ops 121-124)
I20260812 06:20:28.918872 12378 maintenance_manager.cc:643] P 3adf10b27bad47ca95942ca0049a2bb7: LogGCOp(74381d5e18094baead0c6fc8dc8fe0f2) complete. Timing: real 0.003s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:20:28.919312 12463 maintenance_manager.cc:419] P 3adf10b27bad47ca95942ca0049a2bb7: Scheduling FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2): perf score=2.188937
I20260812 06:20:28.937834 12378 maintenance_manager.cc:643] P 3adf10b27bad47ca95942ca0049a2bb7: FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2) complete. Timing: real 0.018s	user 0.014s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6160,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:28.938699 12463 maintenance_manager.cc:419] P 3adf10b27bad47ca95942ca0049a2bb7: Scheduling MajorDeltaCompactionOp(74381d5e18094baead0c6fc8dc8fe0f2): perf score=1.000000
I20260812 06:20:29.126888 12378 maintenance_manager.cc:643] P 3adf10b27bad47ca95942ca0049a2bb7: MajorDeltaCompactionOp(74381d5e18094baead0c6fc8dc8fe0f2) complete. Timing: real 0.188s	user 0.151s	sys 0.035s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836361,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":870,"lbm_read_time_us":15164,"lbm_reads_lt_1ms":674,"lbm_write_time_us":35861,"lbm_writes_lt_1ms":643,"mutex_wait_us":23,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":9472,"thread_start_us":88,"threads_started":1,"update_count":3000}
I20260812 06:20:29.127714 12463 maintenance_manager.cc:419] P 3adf10b27bad47ca95942ca0049a2bb7: Scheduling FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2): perf score=14.095187
I20260812 06:20:29.181461 12378 maintenance_manager.cc:643] P 3adf10b27bad47ca95942ca0049a2bb7: FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2) complete. Timing: real 0.053s	user 0.030s	sys 0.020s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":22858,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:29.181948 12463 maintenance_manager.cc:419] P 3adf10b27bad47ca95942ca0049a2bb7: Scheduling FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2): perf score=2.188937
I20260812 06:20:29.202487 12378 maintenance_manager.cc:643] P 3adf10b27bad47ca95942ca0049a2bb7: FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2) complete. Timing: real 0.020s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5502,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:29.203085 12463 maintenance_manager.cc:419] P 3adf10b27bad47ca95942ca0049a2bb7: Scheduling MajorDeltaCompactionOp(74381d5e18094baead0c6fc8dc8fe0f2): perf score=1.000000
I20260812 06:20:29.372043 12378 maintenance_manager.cc:643] P 3adf10b27bad47ca95942ca0049a2bb7: MajorDeltaCompactionOp(74381d5e18094baead0c6fc8dc8fe0f2) complete. Timing: real 0.169s	user 0.131s	sys 0.037s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733725,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":750,"lbm_read_time_us":10442,"lbm_reads_lt_1ms":564,"lbm_write_time_us":33105,"lbm_writes_lt_1ms":543,"mutex_wait_us":170,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4864,"update_count":2500}
I20260812 06:20:29.372711 12463 maintenance_manager.cc:419] P 3adf10b27bad47ca95942ca0049a2bb7: Scheduling FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2): perf score=14.095187
I20260812 06:20:29.448101 12378 maintenance_manager.cc:643] P 3adf10b27bad47ca95942ca0049a2bb7: FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2) complete. Timing: real 0.075s	user 0.020s	sys 0.044s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":31623,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:29.448717 12463 maintenance_manager.cc:419] P 3adf10b27bad47ca95942ca0049a2bb7: Scheduling FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2): perf score=2.188937
I20260812 06:20:29.463918 12378 maintenance_manager.cc:643] P 3adf10b27bad47ca95942ca0049a2bb7: FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2) complete. Timing: real 0.015s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5653,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:29.464439 12463 maintenance_manager.cc:419] P 3adf10b27bad47ca95942ca0049a2bb7: Scheduling MajorDeltaCompactionOp(74381d5e18094baead0c6fc8dc8fe0f2): perf score=1.000000
I20260812 06:20:29.641544 12378 maintenance_manager.cc:643] P 3adf10b27bad47ca95942ca0049a2bb7: MajorDeltaCompactionOp(74381d5e18094baead0c6fc8dc8fe0f2) complete. Timing: real 0.177s	user 0.112s	sys 0.055s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733722,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1027,"lbm_read_time_us":13763,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28329,"lbm_writes_lt_1ms":543,"mutex_wait_us":52,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8704,"update_count":2500}
I20260812 06:20:29.642170 12463 maintenance_manager.cc:419] P 3adf10b27bad47ca95942ca0049a2bb7: Scheduling FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2): perf score=14.095187
I20260812 06:20:29.707679 12378 maintenance_manager.cc:643] P 3adf10b27bad47ca95942ca0049a2bb7: FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2) complete. Timing: real 0.065s	user 0.020s	sys 0.028s Metrics: {"bytes_written":16409899,"delete_count":0,"lbm_write_time_us":22008,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:29.708318 12463 maintenance_manager.cc:419] P 3adf10b27bad47ca95942ca0049a2bb7: Scheduling FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2): perf score=2.188937
I20260812 06:20:29.722901 12378 maintenance_manager.cc:643] P 3adf10b27bad47ca95942ca0049a2bb7: FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5773,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:29.723502 12463 maintenance_manager.cc:419] P 3adf10b27bad47ca95942ca0049a2bb7: Scheduling MajorDeltaCompactionOp(74381d5e18094baead0c6fc8dc8fe0f2): perf score=1.000000
I20260812 06:20:29.910611 12378 maintenance_manager.cc:643] P 3adf10b27bad47ca95942ca0049a2bb7: MajorDeltaCompactionOp(74381d5e18094baead0c6fc8dc8fe0f2) complete. Timing: real 0.187s	user 0.121s	sys 0.062s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733721,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":983,"lbm_read_time_us":12945,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31547,"lbm_writes_lt_1ms":543,"mutex_wait_us":124,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3328,"update_count":2500}
I20260812 06:20:29.911351 12463 maintenance_manager.cc:419] P 3adf10b27bad47ca95942ca0049a2bb7: Scheduling FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2): perf score=14.095187
I20260812 06:20:29.976656 12378 maintenance_manager.cc:643] P 3adf10b27bad47ca95942ca0049a2bb7: FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2) complete. Timing: real 0.065s	user 0.041s	sys 0.023s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":24163,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:29.977375 12463 maintenance_manager.cc:419] P 3adf10b27bad47ca95942ca0049a2bb7: Scheduling FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2): perf score=2.188937
I20260812 06:20:29.989580 12378 maintenance_manager.cc:643] P 3adf10b27bad47ca95942ca0049a2bb7: FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4774,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:29.990031 12463 maintenance_manager.cc:419] P 3adf10b27bad47ca95942ca0049a2bb7: Scheduling MajorDeltaCompactionOp(74381d5e18094baead0c6fc8dc8fe0f2): perf score=1.000000
I20260812 06:20:30.176213 12378 maintenance_manager.cc:643] P 3adf10b27bad47ca95942ca0049a2bb7: MajorDeltaCompactionOp(74381d5e18094baead0c6fc8dc8fe0f2) complete. Timing: real 0.186s	user 0.122s	sys 0.064s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733727,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":881,"lbm_read_time_us":14207,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31830,"lbm_writes_lt_1ms":543,"mutex_wait_us":45,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7808,"update_count":2500}
I20260812 06:20:30.176854 12463 maintenance_manager.cc:419] P 3adf10b27bad47ca95942ca0049a2bb7: Scheduling FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2): perf score=10.126437
I20260812 06:20:30.210323 12378 maintenance_manager.cc:643] P 3adf10b27bad47ca95942ca0049a2bb7: FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2) complete. Timing: real 0.033s	user 0.018s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14465,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:30.211148 12463 maintenance_manager.cc:419] P 3adf10b27bad47ca95942ca0049a2bb7: Scheduling FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2): perf score=2.188937
I20260812 06:20:30.228310 12378 maintenance_manager.cc:643] P 3adf10b27bad47ca95942ca0049a2bb7: FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2) complete. Timing: real 0.017s	user 0.011s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6672,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:30.228891 12463 maintenance_manager.cc:419] P 3adf10b27bad47ca95942ca0049a2bb7: Scheduling MajorDeltaCompactionOp(74381d5e18094baead0c6fc8dc8fe0f2): perf score=1.000000
I20260812 06:20:30.394098 12378 maintenance_manager.cc:643] P 3adf10b27bad47ca95942ca0049a2bb7: MajorDeltaCompactionOp(74381d5e18094baead0c6fc8dc8fe0f2) complete. Timing: real 0.165s	user 0.110s	sys 0.048s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631311,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":180,"lbm_read_time_us":11932,"lbm_reads_lt_1ms":468,"lbm_write_time_us":25401,"lbm_writes_lt_1ms":443,"mutex_wait_us":34,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":15232,"update_count":2000}
I20260812 06:20:30.395232 12463 maintenance_manager.cc:419] P 3adf10b27bad47ca95942ca0049a2bb7: Scheduling FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2): perf score=10.126437
I20260812 06:20:30.435545 12378 maintenance_manager.cc:643] P 3adf10b27bad47ca95942ca0049a2bb7: FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2) complete. Timing: real 0.040s	user 0.023s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15340,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:30.436084 12463 maintenance_manager.cc:419] P 3adf10b27bad47ca95942ca0049a2bb7: Scheduling FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2): perf score=2.188937
I20260812 06:20:30.448434 12378 maintenance_manager.cc:643] P 3adf10b27bad47ca95942ca0049a2bb7: FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2) complete. Timing: real 0.012s	user 0.005s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4109,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:30.449177 12463 maintenance_manager.cc:419] P 3adf10b27bad47ca95942ca0049a2bb7: Scheduling FlushMRSOp(74381d5e18094baead0c6fc8dc8fe0f2): perf score=1.000000
I20260812 06:20:30.484586 12378 maintenance_manager.cc:643] P 3adf10b27bad47ca95942ca0049a2bb7: FlushMRSOp(74381d5e18094baead0c6fc8dc8fe0f2) complete. Timing: real 0.035s	user 0.033s	sys 0.001s Metrics: {"bytes_written":1234475,"cfile_init":1,"dirs.queue_time_us":97,"dirs.run_cpu_time_us":268,"dirs.run_wall_time_us":1366,"drs_written":1,"lbm_read_time_us":63,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1646,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:20:30.485296 12463 maintenance_manager.cc:419] P 3adf10b27bad47ca95942ca0049a2bb7: Scheduling LogGCOp(74381d5e18094baead0c6fc8dc8fe0f2): free 121006674 bytes of WAL
I20260812 06:20:30.485522 12378 log_reader.cc:385] T 74381d5e18094baead0c6fc8dc8fe0f2: removed 12 log segments from log reader
I20260812 06:20:30.485564 12378 log.cc:1079] T 74381d5e18094baead0c6fc8dc8fe0f2 P 3adf10b27bad47ca95942ca0049a2bb7: Deleting log segment in path: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625276931-12225-0/minicluster-data/ts-0-root/wals/74381d5e18094baead0c6fc8dc8fe0f2/wal-000000026 (ops 125-129)
I20260812 06:20:30.485596 12378 log.cc:1079] T 74381d5e18094baead0c6fc8dc8fe0f2 P 3adf10b27bad47ca95942ca0049a2bb7: Deleting log segment in path: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625276931-12225-0/minicluster-data/ts-0-root/wals/74381d5e18094baead0c6fc8dc8fe0f2/wal-000000027 (ops 130-134)
I20260812 06:20:30.485663 12378 log.cc:1079] T 74381d5e18094baead0c6fc8dc8fe0f2 P 3adf10b27bad47ca95942ca0049a2bb7: Deleting log segment in path: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625276931-12225-0/minicluster-data/ts-0-root/wals/74381d5e18094baead0c6fc8dc8fe0f2/wal-000000028 (ops 135-138)
I20260812 06:20:30.485697 12378 log.cc:1079] T 74381d5e18094baead0c6fc8dc8fe0f2 P 3adf10b27bad47ca95942ca0049a2bb7: Deleting log segment in path: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625276931-12225-0/minicluster-data/ts-0-root/wals/74381d5e18094baead0c6fc8dc8fe0f2/wal-000000029 (ops 139-143)
I20260812 06:20:30.485737 12378 log.cc:1079] T 74381d5e18094baead0c6fc8dc8fe0f2 P 3adf10b27bad47ca95942ca0049a2bb7: Deleting log segment in path: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625276931-12225-0/minicluster-data/ts-0-root/wals/74381d5e18094baead0c6fc8dc8fe0f2/wal-000000030 (ops 144-148)
I20260812 06:20:30.485785 12378 log.cc:1079] T 74381d5e18094baead0c6fc8dc8fe0f2 P 3adf10b27bad47ca95942ca0049a2bb7: Deleting log segment in path: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625276931-12225-0/minicluster-data/ts-0-root/wals/74381d5e18094baead0c6fc8dc8fe0f2/wal-000000031 (ops 149-153)
I20260812 06:20:30.485828 12378 log.cc:1079] T 74381d5e18094baead0c6fc8dc8fe0f2 P 3adf10b27bad47ca95942ca0049a2bb7: Deleting log segment in path: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625276931-12225-0/minicluster-data/ts-0-root/wals/74381d5e18094baead0c6fc8dc8fe0f2/wal-000000032 (ops 154-158)
I20260812 06:20:30.485868 12378 log.cc:1079] T 74381d5e18094baead0c6fc8dc8fe0f2 P 3adf10b27bad47ca95942ca0049a2bb7: Deleting log segment in path: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625276931-12225-0/minicluster-data/ts-0-root/wals/74381d5e18094baead0c6fc8dc8fe0f2/wal-000000033 (ops 159-163)
I20260812 06:20:30.485908 12378 log.cc:1079] T 74381d5e18094baead0c6fc8dc8fe0f2 P 3adf10b27bad47ca95942ca0049a2bb7: Deleting log segment in path: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625276931-12225-0/minicluster-data/ts-0-root/wals/74381d5e18094baead0c6fc8dc8fe0f2/wal-000000034 (ops 164-168)
I20260812 06:20:30.485948 12378 log.cc:1079] T 74381d5e18094baead0c6fc8dc8fe0f2 P 3adf10b27bad47ca95942ca0049a2bb7: Deleting log segment in path: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625276931-12225-0/minicluster-data/ts-0-root/wals/74381d5e18094baead0c6fc8dc8fe0f2/wal-000000035 (ops 169-173)
I20260812 06:20:30.485992 12378 log.cc:1079] T 74381d5e18094baead0c6fc8dc8fe0f2 P 3adf10b27bad47ca95942ca0049a2bb7: Deleting log segment in path: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625276931-12225-0/minicluster-data/ts-0-root/wals/74381d5e18094baead0c6fc8dc8fe0f2/wal-000000036 (ops 174-178)
I20260812 06:20:30.486033 12378 log.cc:1079] T 74381d5e18094baead0c6fc8dc8fe0f2 P 3adf10b27bad47ca95942ca0049a2bb7: Deleting log segment in path: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515625276931-12225-0/minicluster-data/ts-0-root/wals/74381d5e18094baead0c6fc8dc8fe0f2/wal-000000037 (ops 179-183)
I20260812 06:20:30.517057 12378 maintenance_manager.cc:643] P 3adf10b27bad47ca95942ca0049a2bb7: LogGCOp(74381d5e18094baead0c6fc8dc8fe0f2) complete. Timing: real 0.032s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:20:30.517642 12463 maintenance_manager.cc:419] P 3adf10b27bad47ca95942ca0049a2bb7: Scheduling FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2): perf score=3.181125
I20260812 06:20:30.532235 12378 maintenance_manager.cc:643] P 3adf10b27bad47ca95942ca0049a2bb7: FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2) complete. Timing: real 0.014s	user 0.008s	sys 0.005s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":5786,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:30.532917 12463 maintenance_manager.cc:419] P 3adf10b27bad47ca95942ca0049a2bb7: Scheduling FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2): perf score=2.188937
I20260812 06:20:30.548585 12378 maintenance_manager.cc:643] P 3adf10b27bad47ca95942ca0049a2bb7: FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2) complete. Timing: real 0.015s	user 0.004s	sys 0.010s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5755,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:30.549342 12463 maintenance_manager.cc:419] P 3adf10b27bad47ca95942ca0049a2bb7: Scheduling UndoDeltaBlockGCOp(74381d5e18094baead0c6fc8dc8fe0f2): 472 bytes on disk
I20260812 06:20:30.550138 12378 maintenance_manager.cc:643] P 3adf10b27bad47ca95942ca0049a2bb7: UndoDeltaBlockGCOp(74381d5e18094baead0c6fc8dc8fe0f2) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":81,"lbm_reads_lt_1ms":4}
I20260812 06:20:30.551000 12463 maintenance_manager.cc:419] P 3adf10b27bad47ca95942ca0049a2bb7: Scheduling MajorDeltaCompactionOp(74381d5e18094baead0c6fc8dc8fe0f2): perf score=1.000000
I20260812 06:20:30.751173 12378 maintenance_manager.cc:643] P 3adf10b27bad47ca95942ca0049a2bb7: MajorDeltaCompactionOp(74381d5e18094baead0c6fc8dc8fe0f2) complete. Timing: real 0.200s	user 0.141s	sys 0.043s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836361,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":2435,"lbm_read_time_us":12015,"lbm_reads_lt_1ms":674,"lbm_write_time_us":39853,"lbm_writes_lt_1ms":643,"mutex_wait_us":228,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":567,"threads_started":1,"update_count":3000}
I20260812 06:20:30.752602 12463 maintenance_manager.cc:419] P 3adf10b27bad47ca95942ca0049a2bb7: Scheduling FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2): perf score=14.095187
I20260812 06:20:30.817793 12378 maintenance_manager.cc:643] P 3adf10b27bad47ca95942ca0049a2bb7: FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2) complete. Timing: real 0.065s	user 0.032s	sys 0.029s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":30812,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:20:30.818903 12463 maintenance_manager.cc:419] P 3adf10b27bad47ca95942ca0049a2bb7: Scheduling FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2): perf score=2.188937
I20260812 06:20:30.833392 12378 maintenance_manager.cc:643] P 3adf10b27bad47ca95942ca0049a2bb7: FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2) complete. Timing: real 0.014s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5229,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:30.833868 12463 maintenance_manager.cc:419] P 3adf10b27bad47ca95942ca0049a2bb7: Scheduling MajorDeltaCompactionOp(74381d5e18094baead0c6fc8dc8fe0f2): perf score=1.000000
I20260812 06:20:30.975226 12225 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.373s	user 1.962s	sys 0.184s
I20260812 06:20:31.003229 12378 maintenance_manager.cc:643] P 3adf10b27bad47ca95942ca0049a2bb7: MajorDeltaCompactionOp(74381d5e18094baead0c6fc8dc8fe0f2) complete. Timing: real 0.169s	user 0.122s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"lbm_read_time_us":11456,"lbm_reads_lt_1ms":568,"lbm_write_time_us":34220,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":240768,"update_count":2500}
I20260812 06:20:31.003780 12463 maintenance_manager.cc:419] P 3adf10b27bad47ca95942ca0049a2bb7: Scheduling FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2): perf score=10.126437
I20260812 06:20:31.037031 12378 maintenance_manager.cc:643] P 3adf10b27bad47ca95942ca0049a2bb7: FlushDeltaMemStoresOp(74381d5e18094baead0c6fc8dc8fe0f2) complete. Timing: real 0.033s	user 0.023s	sys 0.008s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":13664,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:31.037590 12225 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.062s	user 0.003s	sys 0.000s
I20260812 06:20:31.037930 12463 maintenance_manager.cc:419] P 3adf10b27bad47ca95942ca0049a2bb7: Scheduling MajorDeltaCompactionOp(74381d5e18094baead0c6fc8dc8fe0f2): perf score=1.000000
I20260812 06:20:31.038331 12225 tablet_server.cc:179] TabletServer@127.11.240.65:0 shutting down...
I20260812 06:20:31.137529 12378 maintenance_manager.cc:643] P 3adf10b27bad47ca95942ca0049a2bb7: MajorDeltaCompactionOp(74381d5e18094baead0c6fc8dc8fe0f2) complete. Timing: real 0.099s	user 0.079s	sys 0.019s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16528783,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":421,"lbm_read_time_us":7122,"lbm_reads_lt_1ms":367,"lbm_write_time_us":21986,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":342,"mutex_wait_us":32,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":13696,"update_count":1500}
I20260812 06:20:31.138379 12225 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:31.138846 12225 tablet_replica.cc:333] T 74381d5e18094baead0c6fc8dc8fe0f2 P 3adf10b27bad47ca95942ca0049a2bb7: stopping tablet replica
I20260812 06:20:31.139135 12225 raft_consensus.cc:2243] T 74381d5e18094baead0c6fc8dc8fe0f2 P 3adf10b27bad47ca95942ca0049a2bb7 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:31.139391 12225 raft_consensus.cc:2272] T 74381d5e18094baead0c6fc8dc8fe0f2 P 3adf10b27bad47ca95942ca0049a2bb7 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:31.155649 12225 tablet_server.cc:196] TabletServer@127.11.240.65:0 shutdown complete.
I20260812 06:20:31.170854 12225 master.cc:562] Master@127.11.240.126:34993 shutting down...
I20260812 06:20:31.175514 12225 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 35303195bdb846489d8b2710d8c08fe5 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:31.175714 12225 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 35303195bdb846489d8b2710d8c08fe5 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:31.175813 12225 tablet_replica.cc:333] T 00000000000000000000000000000000 P 35303195bdb846489d8b2710d8c08fe5: stopping tablet replica
I20260812 06:20:31.188787 12225 master.cc:584] Master@127.11.240.126:34993 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (6000 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:20:31.301967 12225 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.11.240.126:37381
I20260812 06:20:31.302439 12225 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:31.304931 12514 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:20:31.305068 12513 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:20:31.304931 12521 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:20:31.305140 12225 server_base.cc:1061] running on GCE node
I20260812 06:20:31.305434 12225 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:31.305480 12225 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:20:31.305496 12225 hybrid_clock.cc:648] HybridClock initialized: now 1786515631305496 us; error 0 us; skew 500 ppm
I20260812 06:20:31.306414 12225 webserver.cc:533] Webserver started at http://127.11.240.126:44375/ using document root <none> and password file <none>
I20260812 06:20:31.306610 12225 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:31.306672 12225 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:31.306753 12225 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:31.307230 12225 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625276931-12225-0/minicluster-data/master-0-root/instance:
uuid: "4741a74d2cf54592bb14d4dba714266f"
format_stamp: "Formatted at 2026-08-12 06:20:31 on dist-test-slave-drl0"
I20260812 06:20:31.308809 12225 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:20:31.310015 12533 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:20:31.310446 12225 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:20:31.310545 12225 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625276931-12225-0/minicluster-data/master-0-root
uuid: "4741a74d2cf54592bb14d4dba714266f"
format_stamp: "Formatted at 2026-08-12 06:20:31 on dist-test-slave-drl0"
I20260812 06:20:31.310636 12225 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625276931-12225-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625276931-12225-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625276931-12225-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:20:31.321997 12225 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:31.322412 12225 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:31.327325 12225 rpc_server.cc:307] RPC server started. Bound to: 127.11.240.126:37381
I20260812 06:20:31.332672 12603 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:20:31.335534 12602 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.11.240.126:37381 every 8 connection(s)
I20260812 06:20:31.340612 12603 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 4741a74d2cf54592bb14d4dba714266f: Bootstrap starting.
I20260812 06:20:31.341467 12603 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 4741a74d2cf54592bb14d4dba714266f: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:31.342546 12603 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 4741a74d2cf54592bb14d4dba714266f: No bootstrap required, opened a new log
I20260812 06:20:31.342949 12603 raft_consensus.cc:359] T 00000000000000000000000000000000 P 4741a74d2cf54592bb14d4dba714266f [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4741a74d2cf54592bb14d4dba714266f" member_type: VOTER }
I20260812 06:20:31.343039 12603 raft_consensus.cc:385] T 00000000000000000000000000000000 P 4741a74d2cf54592bb14d4dba714266f [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:31.343061 12603 raft_consensus.cc:740] T 00000000000000000000000000000000 P 4741a74d2cf54592bb14d4dba714266f [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 4741a74d2cf54592bb14d4dba714266f, State: Initialized, Role: FOLLOWER
I20260812 06:20:31.343227 12603 consensus_queue.cc:260] T 00000000000000000000000000000000 P 4741a74d2cf54592bb14d4dba714266f [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: "4741a74d2cf54592bb14d4dba714266f" member_type: VOTER }
I20260812 06:20:31.343323 12603 raft_consensus.cc:399] T 00000000000000000000000000000000 P 4741a74d2cf54592bb14d4dba714266f [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:31.343351 12603 raft_consensus.cc:493] T 00000000000000000000000000000000 P 4741a74d2cf54592bb14d4dba714266f [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:31.343382 12603 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 4741a74d2cf54592bb14d4dba714266f [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:31.344024 12603 raft_consensus.cc:515] T 00000000000000000000000000000000 P 4741a74d2cf54592bb14d4dba714266f [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4741a74d2cf54592bb14d4dba714266f" member_type: VOTER }
I20260812 06:20:31.344148 12603 leader_election.cc:304] T 00000000000000000000000000000000 P 4741a74d2cf54592bb14d4dba714266f [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: 4741a74d2cf54592bb14d4dba714266f; no voters: 
I20260812 06:20:31.344292 12603 leader_election.cc:290] T 00000000000000000000000000000000 P 4741a74d2cf54592bb14d4dba714266f [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:31.344478 12608 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 4741a74d2cf54592bb14d4dba714266f [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:31.344667 12608 raft_consensus.cc:697] T 00000000000000000000000000000000 P 4741a74d2cf54592bb14d4dba714266f [term 1 LEADER]: Becoming Leader. State: Replica: 4741a74d2cf54592bb14d4dba714266f, State: Running, Role: LEADER
I20260812 06:20:31.344808 12603 sys_catalog.cc:565] T 00000000000000000000000000000000 P 4741a74d2cf54592bb14d4dba714266f [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:31.344830 12608 consensus_queue.cc:237] T 00000000000000000000000000000000 P 4741a74d2cf54592bb14d4dba714266f [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: "4741a74d2cf54592bb14d4dba714266f" member_type: VOTER }
I20260812 06:20:31.345402 12609 sys_catalog.cc:455] T 00000000000000000000000000000000 P 4741a74d2cf54592bb14d4dba714266f [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "4741a74d2cf54592bb14d4dba714266f" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4741a74d2cf54592bb14d4dba714266f" member_type: VOTER } }
I20260812 06:20:31.345566 12609 sys_catalog.cc:458] T 00000000000000000000000000000000 P 4741a74d2cf54592bb14d4dba714266f [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:31.345455 12610 sys_catalog.cc:455] T 00000000000000000000000000000000 P 4741a74d2cf54592bb14d4dba714266f [sys.catalog]: SysCatalogTable state changed. Reason: New leader 4741a74d2cf54592bb14d4dba714266f. Latest consensus state: current_term: 1 leader_uuid: "4741a74d2cf54592bb14d4dba714266f" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "4741a74d2cf54592bb14d4dba714266f" member_type: VOTER } }
I20260812 06:20:31.345755 12610 sys_catalog.cc:458] T 00000000000000000000000000000000 P 4741a74d2cf54592bb14d4dba714266f [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:31.346287 12616 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:31.347251 12616 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:31.347456 12225 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:31.349741 12616 catalog_manager.cc:1383] Generated new cluster ID: 2cb8f616520048d6885d4ab0625df692
I20260812 06:20:31.349860 12616 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:31.383040 12616 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:31.383899 12616 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:31.394431 12616 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 4741a74d2cf54592bb14d4dba714266f: Generated new TSK 0
I20260812 06:20:31.394901 12616 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:31.412257 12225 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:31.414978 12637 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:20:31.414995 12634 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:20:31.415328 12225 server_base.cc:1061] running on GCE node
W20260812 06:20:31.415269 12633 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:20:31.415603 12225 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:31.415652 12225 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:20:31.415673 12225 hybrid_clock.cc:648] HybridClock initialized: now 1786515631415673 us; error 0 us; skew 500 ppm
I20260812 06:20:31.416850 12225 webserver.cc:533] Webserver started at http://127.11.240.65:44273/ using document root <none> and password file <none>
I20260812 06:20:31.417115 12225 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:31.417189 12225 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:31.417286 12225 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:31.417806 12225 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625276931-12225-0/minicluster-data/ts-0-root/instance:
uuid: "eb02244d9bf14c088b6d3e6282823dfb"
format_stamp: "Formatted at 2026-08-12 06:20:31 on dist-test-slave-drl0"
I20260812 06:20:31.419934 12225 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.000s	sys 0.003s
I20260812 06:20:31.421373 12642 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:20:31.421800 12225 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:20:31.421903 12225 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625276931-12225-0/minicluster-data/ts-0-root
uuid: "eb02244d9bf14c088b6d3e6282823dfb"
format_stamp: "Formatted at 2026-08-12 06:20:31 on dist-test-slave-drl0"
I20260812 06:20:31.422013 12225 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625276931-12225-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625276931-12225-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625276931-12225-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:20:31.448763 12225 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:31.449263 12225 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:31.449657 12225 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:31.450177 12225 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:31.450246 12225 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:31.450312 12225 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:31.450374 12225 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:31.455669 12225 rpc_server.cc:307] RPC server started. Bound to: 127.11.240.65:36013
I20260812 06:20:31.456404 12742 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.11.240.65:36013 every 8 connection(s)
I20260812 06:20:31.463032 12744 heartbeater.cc:344] Connected to a master server at 127.11.240.126:37381
I20260812 06:20:31.463191 12744 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:31.463479 12744 heartbeater.cc:507] Master 127.11.240.126:37381 requested a full tablet report, sending...
I20260812 06:20:31.464277 12556 ts_manager.cc:194] Registered new tserver with Master: eb02244d9bf14c088b6d3e6282823dfb (127.11.240.65:36013)
I20260812 06:20:31.464737 12225 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.008109954s
I20260812 06:20:31.465205 12556 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:44942
I20260812 06:20:31.474198 12556 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:44952:
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:20:31.485361 12683 tablet_service.cc:1511] Processing CreateTablet for tablet bd02ca77f9ad4883803840dff3522252 (DEFAULT_TABLE table=heavy-update-compaction-test [id=47cbe4e7953941d79790eebf762eb00f]), partition=
I20260812 06:20:31.485702 12683 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet bd02ca77f9ad4883803840dff3522252. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:31.488019 12761 tablet_bootstrap.cc:492] T bd02ca77f9ad4883803840dff3522252 P eb02244d9bf14c088b6d3e6282823dfb: Bootstrap starting.
I20260812 06:20:31.489354 12761 tablet_bootstrap.cc:654] T bd02ca77f9ad4883803840dff3522252 P eb02244d9bf14c088b6d3e6282823dfb: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:31.491113 12761 tablet_bootstrap.cc:492] T bd02ca77f9ad4883803840dff3522252 P eb02244d9bf14c088b6d3e6282823dfb: No bootstrap required, opened a new log
I20260812 06:20:31.491251 12761 ts_tablet_manager.cc:1403] T bd02ca77f9ad4883803840dff3522252 P eb02244d9bf14c088b6d3e6282823dfb: Time spent bootstrapping tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:20:31.491715 12761 raft_consensus.cc:359] T bd02ca77f9ad4883803840dff3522252 P eb02244d9bf14c088b6d3e6282823dfb [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "eb02244d9bf14c088b6d3e6282823dfb" member_type: VOTER last_known_addr { host: "127.11.240.65" port: 36013 } }
I20260812 06:20:31.491808 12761 raft_consensus.cc:385] T bd02ca77f9ad4883803840dff3522252 P eb02244d9bf14c088b6d3e6282823dfb [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:31.491832 12761 raft_consensus.cc:740] T bd02ca77f9ad4883803840dff3522252 P eb02244d9bf14c088b6d3e6282823dfb [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: eb02244d9bf14c088b6d3e6282823dfb, State: Initialized, Role: FOLLOWER
I20260812 06:20:31.491981 12761 consensus_queue.cc:260] T bd02ca77f9ad4883803840dff3522252 P eb02244d9bf14c088b6d3e6282823dfb [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: "eb02244d9bf14c088b6d3e6282823dfb" member_type: VOTER last_known_addr { host: "127.11.240.65" port: 36013 } }
I20260812 06:20:31.492056 12761 raft_consensus.cc:399] T bd02ca77f9ad4883803840dff3522252 P eb02244d9bf14c088b6d3e6282823dfb [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:31.492079 12761 raft_consensus.cc:493] T bd02ca77f9ad4883803840dff3522252 P eb02244d9bf14c088b6d3e6282823dfb [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:31.492110 12761 raft_consensus.cc:3060] T bd02ca77f9ad4883803840dff3522252 P eb02244d9bf14c088b6d3e6282823dfb [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:31.492851 12761 raft_consensus.cc:515] T bd02ca77f9ad4883803840dff3522252 P eb02244d9bf14c088b6d3e6282823dfb [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "eb02244d9bf14c088b6d3e6282823dfb" member_type: VOTER last_known_addr { host: "127.11.240.65" port: 36013 } }
I20260812 06:20:31.492972 12761 leader_election.cc:304] T bd02ca77f9ad4883803840dff3522252 P eb02244d9bf14c088b6d3e6282823dfb [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: eb02244d9bf14c088b6d3e6282823dfb; no voters: 
I20260812 06:20:31.493234 12761 leader_election.cc:290] T bd02ca77f9ad4883803840dff3522252 P eb02244d9bf14c088b6d3e6282823dfb [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:31.493419 12763 raft_consensus.cc:2804] T bd02ca77f9ad4883803840dff3522252 P eb02244d9bf14c088b6d3e6282823dfb [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:31.493633 12744 heartbeater.cc:499] Master 127.11.240.126:37381 was elected leader, sending a full tablet report...
I20260812 06:20:31.493680 12763 raft_consensus.cc:697] T bd02ca77f9ad4883803840dff3522252 P eb02244d9bf14c088b6d3e6282823dfb [term 1 LEADER]: Becoming Leader. State: Replica: eb02244d9bf14c088b6d3e6282823dfb, State: Running, Role: LEADER
I20260812 06:20:31.493854 12763 consensus_queue.cc:237] T bd02ca77f9ad4883803840dff3522252 P eb02244d9bf14c088b6d3e6282823dfb [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: "eb02244d9bf14c088b6d3e6282823dfb" member_type: VOTER last_known_addr { host: "127.11.240.65" port: 36013 } }
I20260812 06:20:31.493903 12761 ts_tablet_manager.cc:1434] T bd02ca77f9ad4883803840dff3522252 P eb02244d9bf14c088b6d3e6282823dfb: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:20:31.495517 12556 catalog_manager.cc:5719] T bd02ca77f9ad4883803840dff3522252 P eb02244d9bf14c088b6d3e6282823dfb reported cstate change: term changed from 0 to 1, leader changed from <none> to eb02244d9bf14c088b6d3e6282823dfb (127.11.240.65). New cstate: current_term: 1 leader_uuid: "eb02244d9bf14c088b6d3e6282823dfb" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "eb02244d9bf14c088b6d3e6282823dfb" member_type: VOTER last_known_addr { host: "127.11.240.65" port: 36013 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:31.562312 12225 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.060s	user 0.025s	sys 0.000s
I20260812 06:20:31.707436 12745 maintenance_manager.cc:419] P eb02244d9bf14c088b6d3e6282823dfb: Scheduling FlushMRSOp(bd02ca77f9ad4883803840dff3522252): perf score=15.086190
I20260812 06:20:31.844945 12647 maintenance_manager.cc:643] P eb02244d9bf14c088b6d3e6282823dfb: FlushMRSOp(bd02ca77f9ad4883803840dff3522252) complete. Timing: real 0.137s	user 0.103s	sys 0.032s Metrics: {"bytes_written":8779416,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":90,"dirs.run_cpu_time_us":239,"dirs.run_wall_time_us":873,"drs_written":1,"lbm_read_time_us":102,"lbm_reads_lt_1ms":4,"lbm_write_time_us":32830,"lbm_writes_lt_1ms":581,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":591872,"update_count":1070}
I20260812 06:20:31.846060 12745 maintenance_manager.cc:419] P eb02244d9bf14c088b6d3e6282823dfb: Scheduling LogGCOp(bd02ca77f9ad4883803840dff3522252): free 20743880 bytes of WAL
I20260812 06:20:31.846465 12647 log_reader.cc:385] T bd02ca77f9ad4883803840dff3522252: removed 2 log segments from log reader
I20260812 06:20:31.846582 12647 log.cc:1079] T bd02ca77f9ad4883803840dff3522252 P eb02244d9bf14c088b6d3e6282823dfb: Deleting log segment in path: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625276931-12225-0/minicluster-data/ts-0-root/wals/bd02ca77f9ad4883803840dff3522252/wal-000000001 (ops 1-6)
I20260812 06:20:31.846654 12647 log.cc:1079] T bd02ca77f9ad4883803840dff3522252 P eb02244d9bf14c088b6d3e6282823dfb: Deleting log segment in path: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625276931-12225-0/minicluster-data/ts-0-root/wals/bd02ca77f9ad4883803840dff3522252/wal-000000002 (ops 7-11)
I20260812 06:20:31.852777 12647 maintenance_manager.cc:643] P eb02244d9bf14c088b6d3e6282823dfb: LogGCOp(bd02ca77f9ad4883803840dff3522252) complete. Timing: real 0.006s	user 0.000s	sys 0.005s Metrics: {}
I20260812 06:20:31.853147 12745 maintenance_manager.cc:419] P eb02244d9bf14c088b6d3e6282823dfb: Scheduling FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252): perf score=1.196750
I20260812 06:20:31.867236 12647 maintenance_manager.cc:643] P eb02244d9bf14c088b6d3e6282823dfb: FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252) complete. Timing: real 0.014s	user 0.001s	sys 0.012s Metrics: {"bytes_written":3118055,"delete_count":0,"lbm_write_time_us":5346,"lbm_writes_lt_1ms":79,"reinsert_count":0,"update_count":380}
I20260812 06:20:31.867740 12745 maintenance_manager.cc:419] P eb02244d9bf14c088b6d3e6282823dfb: Scheduling MajorDeltaCompactionOp(bd02ca77f9ad4883803840dff3522252): perf score=1.000000
I20260812 06:20:32.010696 12647 maintenance_manager.cc:643] P eb02244d9bf14c088b6d3e6282823dfb: MajorDeltaCompactionOp(bd02ca77f9ad4883803840dff3522252) complete. Timing: real 0.143s	user 0.078s	sys 0.065s Metrics: {"cfile_cache_miss":322,"cfile_cache_miss_bytes":16159599,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":285,"lbm_read_time_us":9868,"lbm_reads_lt_1ms":358,"lbm_write_time_us":22832,"lbm_writes_lt_1ms":333,"peak_mem_usage":36812022,"reinsert_count":0,"spinlock_wait_cycles":6272,"thread_start_us":379,"threads_started":5,"update_count":1450}
I20260812 06:20:32.011437 12745 maintenance_manager.cc:419] P eb02244d9bf14c088b6d3e6282823dfb: Scheduling FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252): perf score=10.126437
I20260812 06:20:32.057361 12647 maintenance_manager.cc:643] P eb02244d9bf14c088b6d3e6282823dfb: FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252) complete. Timing: real 0.046s	user 0.019s	sys 0.022s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":18977,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:32.057886 12745 maintenance_manager.cc:419] P eb02244d9bf14c088b6d3e6282823dfb: Scheduling FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252): perf score=2.188937
I20260812 06:20:32.069851 12647 maintenance_manager.cc:643] P eb02244d9bf14c088b6d3e6282823dfb: FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252) complete. Timing: real 0.012s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4718,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:32.070279 12745 maintenance_manager.cc:419] P eb02244d9bf14c088b6d3e6282823dfb: Scheduling UndoDeltaBlockGCOp(bd02ca77f9ad4883803840dff3522252): 12719217 bytes on disk
I20260812 06:20:32.070900 12647 maintenance_manager.cc:643] P eb02244d9bf14c088b6d3e6282823dfb: UndoDeltaBlockGCOp(bd02ca77f9ad4883803840dff3522252) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":81,"lbm_reads_lt_1ms":4}
I20260812 06:20:32.071592 12745 maintenance_manager.cc:419] P eb02244d9bf14c088b6d3e6282823dfb: Scheduling MajorDeltaCompactionOp(bd02ca77f9ad4883803840dff3522252): perf score=1.000000
I20260812 06:20:32.214867 12647 maintenance_manager.cc:643] P eb02244d9bf14c088b6d3e6282823dfb: MajorDeltaCompactionOp(bd02ca77f9ad4883803840dff3522252) complete. Timing: real 0.143s	user 0.087s	sys 0.055s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":353,"lbm_read_time_us":10527,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27277,"lbm_writes_lt_1ms":443,"mutex_wait_us":46,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":34304,"update_count":2000}
I20260812 06:20:32.215509 12745 maintenance_manager.cc:419] P eb02244d9bf14c088b6d3e6282823dfb: Scheduling FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252): perf score=10.126437
I20260812 06:20:32.262377 12647 maintenance_manager.cc:643] P eb02244d9bf14c088b6d3e6282823dfb: FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252) complete. Timing: real 0.047s	user 0.019s	sys 0.019s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":18330,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:32.263367 12745 maintenance_manager.cc:419] P eb02244d9bf14c088b6d3e6282823dfb: Scheduling FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252): perf score=2.188937
I20260812 06:20:32.281818 12647 maintenance_manager.cc:643] P eb02244d9bf14c088b6d3e6282823dfb: FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252) complete. Timing: real 0.018s	user 0.004s	sys 0.012s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":7735,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:32.282431 12745 maintenance_manager.cc:419] P eb02244d9bf14c088b6d3e6282823dfb: Scheduling MajorDeltaCompactionOp(bd02ca77f9ad4883803840dff3522252): perf score=1.000000
I20260812 06:20:32.430629 12647 maintenance_manager.cc:643] P eb02244d9bf14c088b6d3e6282823dfb: MajorDeltaCompactionOp(bd02ca77f9ad4883803840dff3522252) complete. Timing: real 0.148s	user 0.128s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672275,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":230,"lbm_read_time_us":10870,"lbm_reads_lt_1ms":472,"lbm_write_time_us":29461,"lbm_writes_lt_1ms":443,"mutex_wait_us":126,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:20:32.431264 12745 maintenance_manager.cc:419] P eb02244d9bf14c088b6d3e6282823dfb: Scheduling FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252): perf score=10.126437
I20260812 06:20:32.494756 12647 maintenance_manager.cc:643] P eb02244d9bf14c088b6d3e6282823dfb: FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252) complete. Timing: real 0.063s	user 0.028s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17083,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:32.495467 12745 maintenance_manager.cc:419] P eb02244d9bf14c088b6d3e6282823dfb: Scheduling FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252): perf score=2.188937
I20260812 06:20:32.509363 12647 maintenance_manager.cc:643] P eb02244d9bf14c088b6d3e6282823dfb: FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252) complete. Timing: real 0.014s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5582,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:32.509961 12745 maintenance_manager.cc:419] P eb02244d9bf14c088b6d3e6282823dfb: Scheduling MajorDeltaCompactionOp(bd02ca77f9ad4883803840dff3522252): perf score=1.000000
I20260812 06:20:32.681914 12647 maintenance_manager.cc:643] P eb02244d9bf14c088b6d3e6282823dfb: MajorDeltaCompactionOp(bd02ca77f9ad4883803840dff3522252) complete. Timing: real 0.172s	user 0.096s	sys 0.076s 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":570,"lbm_read_time_us":13248,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27799,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:20:32.682587 12745 maintenance_manager.cc:419] P eb02244d9bf14c088b6d3e6282823dfb: Scheduling FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252): perf score=10.126437
I20260812 06:20:32.720647 12647 maintenance_manager.cc:643] P eb02244d9bf14c088b6d3e6282823dfb: FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252) complete. Timing: real 0.038s	user 0.024s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16243,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:32.721300 12745 maintenance_manager.cc:419] P eb02244d9bf14c088b6d3e6282823dfb: Scheduling FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252): perf score=2.188937
I20260812 06:20:32.737232 12647 maintenance_manager.cc:643] P eb02244d9bf14c088b6d3e6282823dfb: FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252) complete. Timing: real 0.016s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5929,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:32.737973 12745 maintenance_manager.cc:419] P eb02244d9bf14c088b6d3e6282823dfb: Scheduling MajorDeltaCompactionOp(bd02ca77f9ad4883803840dff3522252): perf score=1.000000
I20260812 06:20:32.882215 12647 maintenance_manager.cc:643] P eb02244d9bf14c088b6d3e6282823dfb: MajorDeltaCompactionOp(bd02ca77f9ad4883803840dff3522252) complete. Timing: real 0.144s	user 0.128s	sys 0.015s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":392,"lbm_read_time_us":12129,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27051,"lbm_writes_lt_1ms":443,"mutex_wait_us":43,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":22016,"update_count":2000}
I20260812 06:20:32.882830 12745 maintenance_manager.cc:419] P eb02244d9bf14c088b6d3e6282823dfb: Scheduling FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252): perf score=10.126437
I20260812 06:20:32.940265 12647 maintenance_manager.cc:643] P eb02244d9bf14c088b6d3e6282823dfb: FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252) complete. Timing: real 0.057s	user 0.029s	sys 0.013s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":18395,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:32.940894 12745 maintenance_manager.cc:419] P eb02244d9bf14c088b6d3e6282823dfb: Scheduling FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252): perf score=2.188937
I20260812 06:20:32.954749 12647 maintenance_manager.cc:643] P eb02244d9bf14c088b6d3e6282823dfb: FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252) complete. Timing: real 0.014s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5221,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:32.955250 12745 maintenance_manager.cc:419] P eb02244d9bf14c088b6d3e6282823dfb: Scheduling MajorDeltaCompactionOp(bd02ca77f9ad4883803840dff3522252): perf score=1.000000
I20260812 06:20:33.093204 12647 maintenance_manager.cc:643] P eb02244d9bf14c088b6d3e6282823dfb: MajorDeltaCompactionOp(bd02ca77f9ad4883803840dff3522252) complete. Timing: real 0.138s	user 0.088s	sys 0.049s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":183,"lbm_read_time_us":10341,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28083,"lbm_writes_lt_1ms":443,"mutex_wait_us":49,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2560,"update_count":2000}
I20260812 06:20:33.093886 12745 maintenance_manager.cc:419] P eb02244d9bf14c088b6d3e6282823dfb: Scheduling FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252): perf score=10.126437
I20260812 06:20:33.152859 12647 maintenance_manager.cc:643] P eb02244d9bf14c088b6d3e6282823dfb: FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252) complete. Timing: real 0.059s	user 0.038s	sys 0.008s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":21033,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:33.153383 12745 maintenance_manager.cc:419] P eb02244d9bf14c088b6d3e6282823dfb: Scheduling FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252): perf score=2.188937
I20260812 06:20:33.165128 12647 maintenance_manager.cc:643] P eb02244d9bf14c088b6d3e6282823dfb: FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4670,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:33.166543 12745 maintenance_manager.cc:419] P eb02244d9bf14c088b6d3e6282823dfb: Scheduling MajorDeltaCompactionOp(bd02ca77f9ad4883803840dff3522252): perf score=1.000000
I20260812 06:20:33.306706 12647 maintenance_manager.cc:643] P eb02244d9bf14c088b6d3e6282823dfb: MajorDeltaCompactionOp(bd02ca77f9ad4883803840dff3522252) complete. Timing: real 0.140s	user 0.112s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":787,"lbm_read_time_us":11950,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25280,"lbm_writes_lt_1ms":443,"mutex_wait_us":26,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":25856,"update_count":2000}
I20260812 06:20:33.307526 12745 maintenance_manager.cc:419] P eb02244d9bf14c088b6d3e6282823dfb: Scheduling FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252): perf score=10.126437
I20260812 06:20:33.369076 12647 maintenance_manager.cc:643] P eb02244d9bf14c088b6d3e6282823dfb: FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252) complete. Timing: real 0.061s	user 0.019s	sys 0.031s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16882,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:33.369693 12745 maintenance_manager.cc:419] P eb02244d9bf14c088b6d3e6282823dfb: Scheduling FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252): perf score=2.188937
I20260812 06:20:33.382474 12647 maintenance_manager.cc:643] P eb02244d9bf14c088b6d3e6282823dfb: FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252) complete. Timing: real 0.013s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5270,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:33.383050 12745 maintenance_manager.cc:419] P eb02244d9bf14c088b6d3e6282823dfb: Scheduling FlushMRSOp(bd02ca77f9ad4883803840dff3522252): perf score=1.000000
I20260812 06:20:33.418112 12647 maintenance_manager.cc:643] P eb02244d9bf14c088b6d3e6282823dfb: FlushMRSOp(bd02ca77f9ad4883803840dff3522252) complete. Timing: real 0.035s	user 0.030s	sys 0.001s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":80,"dirs.run_cpu_time_us":268,"dirs.run_wall_time_us":1469,"drs_written":1,"lbm_read_time_us":36,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1762,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:20:33.418717 12745 maintenance_manager.cc:419] P eb02244d9bf14c088b6d3e6282823dfb: Scheduling UndoDeltaBlockGCOp(bd02ca77f9ad4883803840dff3522252): 473 bytes on disk
I20260812 06:20:33.419142 12647 maintenance_manager.cc:643] P eb02244d9bf14c088b6d3e6282823dfb: UndoDeltaBlockGCOp(bd02ca77f9ad4883803840dff3522252) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4}
I20260812 06:20:33.419564 12745 maintenance_manager.cc:419] P eb02244d9bf14c088b6d3e6282823dfb: Scheduling MajorDeltaCompactionOp(bd02ca77f9ad4883803840dff3522252): perf score=1.000000
I20260812 06:20:33.587989 12647 maintenance_manager.cc:643] P eb02244d9bf14c088b6d3e6282823dfb: MajorDeltaCompactionOp(bd02ca77f9ad4883803840dff3522252) complete. Timing: real 0.168s	user 0.106s	sys 0.062s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1857,"lbm_read_time_us":11617,"lbm_reads_lt_1ms":464,"lbm_write_time_us":27151,"lbm_writes_lt_1ms":443,"mutex_wait_us":30,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11264,"update_count":2000}
I20260812 06:20:33.588491 12745 maintenance_manager.cc:419] P eb02244d9bf14c088b6d3e6282823dfb: Scheduling LogGCOp(bd02ca77f9ad4883803840dff3522252): free 124710258 bytes of WAL
I20260812 06:20:33.588749 12647 log_reader.cc:385] T bd02ca77f9ad4883803840dff3522252: removed 12 log segments from log reader
I20260812 06:20:33.588819 12647 log.cc:1079] T bd02ca77f9ad4883803840dff3522252 P eb02244d9bf14c088b6d3e6282823dfb: Deleting log segment in path: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625276931-12225-0/minicluster-data/ts-0-root/wals/bd02ca77f9ad4883803840dff3522252/wal-000000003 (ops 12-16)
I20260812 06:20:33.588908 12647 log.cc:1079] T bd02ca77f9ad4883803840dff3522252 P eb02244d9bf14c088b6d3e6282823dfb: Deleting log segment in path: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625276931-12225-0/minicluster-data/ts-0-root/wals/bd02ca77f9ad4883803840dff3522252/wal-000000004 (ops 17-21)
I20260812 06:20:33.588977 12647 log.cc:1079] T bd02ca77f9ad4883803840dff3522252 P eb02244d9bf14c088b6d3e6282823dfb: Deleting log segment in path: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625276931-12225-0/minicluster-data/ts-0-root/wals/bd02ca77f9ad4883803840dff3522252/wal-000000005 (ops 22-26)
I20260812 06:20:33.589025 12647 log.cc:1079] T bd02ca77f9ad4883803840dff3522252 P eb02244d9bf14c088b6d3e6282823dfb: Deleting log segment in path: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625276931-12225-0/minicluster-data/ts-0-root/wals/bd02ca77f9ad4883803840dff3522252/wal-000000006 (ops 27-31)
I20260812 06:20:33.589097 12647 log.cc:1079] T bd02ca77f9ad4883803840dff3522252 P eb02244d9bf14c088b6d3e6282823dfb: Deleting log segment in path: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625276931-12225-0/minicluster-data/ts-0-root/wals/bd02ca77f9ad4883803840dff3522252/wal-000000007 (ops 32-36)
I20260812 06:20:33.589164 12647 log.cc:1079] T bd02ca77f9ad4883803840dff3522252 P eb02244d9bf14c088b6d3e6282823dfb: Deleting log segment in path: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625276931-12225-0/minicluster-data/ts-0-root/wals/bd02ca77f9ad4883803840dff3522252/wal-000000008 (ops 37-41)
I20260812 06:20:33.589212 12647 log.cc:1079] T bd02ca77f9ad4883803840dff3522252 P eb02244d9bf14c088b6d3e6282823dfb: Deleting log segment in path: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625276931-12225-0/minicluster-data/ts-0-root/wals/bd02ca77f9ad4883803840dff3522252/wal-000000009 (ops 42-46)
I20260812 06:20:33.589254 12647 log.cc:1079] T bd02ca77f9ad4883803840dff3522252 P eb02244d9bf14c088b6d3e6282823dfb: Deleting log segment in path: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625276931-12225-0/minicluster-data/ts-0-root/wals/bd02ca77f9ad4883803840dff3522252/wal-000000010 (ops 47-51)
I20260812 06:20:33.589304 12647 log.cc:1079] T bd02ca77f9ad4883803840dff3522252 P eb02244d9bf14c088b6d3e6282823dfb: Deleting log segment in path: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625276931-12225-0/minicluster-data/ts-0-root/wals/bd02ca77f9ad4883803840dff3522252/wal-000000011 (ops 52-56)
I20260812 06:20:33.589346 12647 log.cc:1079] T bd02ca77f9ad4883803840dff3522252 P eb02244d9bf14c088b6d3e6282823dfb: Deleting log segment in path: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625276931-12225-0/minicluster-data/ts-0-root/wals/bd02ca77f9ad4883803840dff3522252/wal-000000012 (ops 57-61)
I20260812 06:20:33.589388 12647 log.cc:1079] T bd02ca77f9ad4883803840dff3522252 P eb02244d9bf14c088b6d3e6282823dfb: Deleting log segment in path: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625276931-12225-0/minicluster-data/ts-0-root/wals/bd02ca77f9ad4883803840dff3522252/wal-000000013 (ops 62-66)
I20260812 06:20:33.589429 12647 log.cc:1079] T bd02ca77f9ad4883803840dff3522252 P eb02244d9bf14c088b6d3e6282823dfb: Deleting log segment in path: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625276931-12225-0/minicluster-data/ts-0-root/wals/bd02ca77f9ad4883803840dff3522252/wal-000000014 (ops 67-71)
I20260812 06:20:33.624303 12647 maintenance_manager.cc:643] P eb02244d9bf14c088b6d3e6282823dfb: LogGCOp(bd02ca77f9ad4883803840dff3522252) complete. Timing: real 0.036s	user 0.000s	sys 0.034s Metrics: {}
I20260812 06:20:33.624922 12745 maintenance_manager.cc:419] P eb02244d9bf14c088b6d3e6282823dfb: Scheduling FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252): perf score=15.087375
I20260812 06:20:33.670080 12647 maintenance_manager.cc:643] P eb02244d9bf14c088b6d3e6282823dfb: FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252) complete. Timing: real 0.045s	user 0.022s	sys 0.018s Metrics: {"bytes_written":16820142,"delete_count":0,"lbm_write_time_us":19732,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:20:33.670534 12745 maintenance_manager.cc:419] P eb02244d9bf14c088b6d3e6282823dfb: Scheduling FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252): perf score=2.188937
I20260812 06:20:33.696373 12647 maintenance_manager.cc:643] P eb02244d9bf14c088b6d3e6282823dfb: FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252) complete. Timing: real 0.026s	user 0.009s	sys 0.015s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4886,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:33.696959 12745 maintenance_manager.cc:419] P eb02244d9bf14c088b6d3e6282823dfb: Scheduling FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252): perf score=2.188937
I20260812 06:20:33.706851 12647 maintenance_manager.cc:643] P eb02244d9bf14c088b6d3e6282823dfb: FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3774,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:33.707548 12745 maintenance_manager.cc:419] P eb02244d9bf14c088b6d3e6282823dfb: Scheduling MajorDeltaCompactionOp(bd02ca77f9ad4883803840dff3522252): perf score=1.000000
I20260812 06:20:33.940837 12647 maintenance_manager.cc:643] P eb02244d9bf14c088b6d3e6282823dfb: MajorDeltaCompactionOp(bd02ca77f9ad4883803840dff3522252) complete. Timing: real 0.233s	user 0.149s	sys 0.084s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877206,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1248,"lbm_read_time_us":17321,"lbm_reads_lt_1ms":673,"lbm_write_time_us":37566,"lbm_writes_lt_1ms":643,"mutex_wait_us":302,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2816,"update_count":3000}
I20260812 06:20:33.941593 12745 maintenance_manager.cc:419] P eb02244d9bf14c088b6d3e6282823dfb: Scheduling FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252): perf score=14.095187
I20260812 06:20:34.017083 12647 maintenance_manager.cc:643] P eb02244d9bf14c088b6d3e6282823dfb: FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252) complete. Timing: real 0.075s	user 0.045s	sys 0.028s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":26824,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:34.017625 12745 maintenance_manager.cc:419] P eb02244d9bf14c088b6d3e6282823dfb: Scheduling FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252): perf score=3.181125
I20260812 06:20:34.031273 12647 maintenance_manager.cc:643] P eb02244d9bf14c088b6d3e6282823dfb: FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252) complete. Timing: real 0.013s	user 0.008s	sys 0.005s Metrics: {"bytes_written":4512901,"delete_count":0,"lbm_write_time_us":5379,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:34.031728 12745 maintenance_manager.cc:419] P eb02244d9bf14c088b6d3e6282823dfb: Scheduling FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252): perf score=2.188937
I20260812 06:20:34.042728 12647 maintenance_manager.cc:643] P eb02244d9bf14c088b6d3e6282823dfb: FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4371,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:34.043179 12745 maintenance_manager.cc:419] P eb02244d9bf14c088b6d3e6282823dfb: Scheduling MajorDeltaCompactionOp(bd02ca77f9ad4883803840dff3522252): perf score=1.000000
I20260812 06:20:34.263600 12647 maintenance_manager.cc:643] P eb02244d9bf14c088b6d3e6282823dfb: MajorDeltaCompactionOp(bd02ca77f9ad4883803840dff3522252) complete. Timing: real 0.220s	user 0.146s	sys 0.071s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877208,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":632,"lbm_read_time_us":16859,"lbm_reads_lt_1ms":673,"lbm_write_time_us":36558,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":642,"mutex_wait_us":49,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":3000}
I20260812 06:20:34.264518 12745 maintenance_manager.cc:419] P eb02244d9bf14c088b6d3e6282823dfb: Scheduling FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252): perf score=16.079562
I20260812 06:20:34.324633 12647 maintenance_manager.cc:643] P eb02244d9bf14c088b6d3e6282823dfb: FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252) complete. Timing: real 0.060s	user 0.030s	sys 0.028s Metrics: {"bytes_written":17804726,"delete_count":0,"lbm_write_time_us":27256,"lbm_writes_lt_1ms":437,"reinsert_count":0,"update_count":2170}
I20260812 06:20:34.325109 12745 maintenance_manager.cc:419] P eb02244d9bf14c088b6d3e6282823dfb: Scheduling FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252): perf score=1.196750
I20260812 06:20:34.352875 12647 maintenance_manager.cc:643] P eb02244d9bf14c088b6d3e6282823dfb: FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252) complete. Timing: real 0.028s	user 0.008s	sys 0.004s Metrics: {"bytes_written":2707805,"delete_count":0,"lbm_write_time_us":4760,"lbm_writes_lt_1ms":69,"reinsert_count":0,"update_count":330}
I20260812 06:20:34.353439 12745 maintenance_manager.cc:419] P eb02244d9bf14c088b6d3e6282823dfb: Scheduling FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252): perf score=2.188937
I20260812 06:20:34.365301 12647 maintenance_manager.cc:643] P eb02244d9bf14c088b6d3e6282823dfb: FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252) complete. Timing: real 0.012s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4780,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:34.366032 12745 maintenance_manager.cc:419] P eb02244d9bf14c088b6d3e6282823dfb: Scheduling MajorDeltaCompactionOp(bd02ca77f9ad4883803840dff3522252): perf score=1.000000
I20260812 06:20:34.663640 12647 maintenance_manager.cc:643] P eb02244d9bf14c088b6d3e6282823dfb: MajorDeltaCompactionOp(bd02ca77f9ad4883803840dff3522252) complete. Timing: real 0.297s	user 0.217s	sys 0.074s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877189,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":830,"lbm_read_time_us":21743,"lbm_reads_1-10_ms":1,"lbm_reads_lt_1ms":672,"lbm_write_time_us":44746,"lbm_writes_lt_1ms":643,"mutex_wait_us":556,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":14208,"update_count":3000}
I20260812 06:20:34.664227 12745 maintenance_manager.cc:419] P eb02244d9bf14c088b6d3e6282823dfb: Scheduling FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252): perf score=14.095187
I20260812 06:20:34.707639 12647 maintenance_manager.cc:643] P eb02244d9bf14c088b6d3e6282823dfb: FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252) complete. Timing: real 0.043s	user 0.027s	sys 0.016s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":19631,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:34.708182 12745 maintenance_manager.cc:419] P eb02244d9bf14c088b6d3e6282823dfb: Scheduling MajorDeltaCompactionOp(bd02ca77f9ad4883803840dff3522252): perf score=1.000000
I20260812 06:20:34.869401 12647 maintenance_manager.cc:643] P eb02244d9bf14c088b6d3e6282823dfb: MajorDeltaCompactionOp(bd02ca77f9ad4883803840dff3522252) complete. Timing: real 0.161s	user 0.103s	sys 0.056s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672156,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":398,"lbm_read_time_us":12982,"lbm_reads_lt_1ms":463,"lbm_write_time_us":26852,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6144,"update_count":2000}
I20260812 06:20:34.870141 12745 maintenance_manager.cc:419] P eb02244d9bf14c088b6d3e6282823dfb: Scheduling FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252): perf score=10.126437
I20260812 06:20:34.913609 12647 maintenance_manager.cc:643] P eb02244d9bf14c088b6d3e6282823dfb: FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252) complete. Timing: real 0.043s	user 0.017s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15434,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:34.914201 12745 maintenance_manager.cc:419] P eb02244d9bf14c088b6d3e6282823dfb: Scheduling FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252): perf score=2.188937
I20260812 06:20:34.926229 12647 maintenance_manager.cc:643] P eb02244d9bf14c088b6d3e6282823dfb: FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252) complete. Timing: real 0.012s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5010,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:34.927052 12745 maintenance_manager.cc:419] P eb02244d9bf14c088b6d3e6282823dfb: Scheduling MajorDeltaCompactionOp(bd02ca77f9ad4883803840dff3522252): perf score=1.000000
I20260812 06:20:35.067730 12647 maintenance_manager.cc:643] P eb02244d9bf14c088b6d3e6282823dfb: MajorDeltaCompactionOp(bd02ca77f9ad4883803840dff3522252) complete. Timing: real 0.140s	user 0.097s	sys 0.043s 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":501,"lbm_read_time_us":10101,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26251,"lbm_writes_lt_1ms":443,"mutex_wait_us":98,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3840,"update_count":2000}
I20260812 06:20:35.068420 12745 maintenance_manager.cc:419] P eb02244d9bf14c088b6d3e6282823dfb: Scheduling FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252): perf score=10.126437
I20260812 06:20:35.103434 12647 maintenance_manager.cc:643] P eb02244d9bf14c088b6d3e6282823dfb: FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252) complete. Timing: real 0.035s	user 0.024s	sys 0.009s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":14339,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:35.104141 12745 maintenance_manager.cc:419] P eb02244d9bf14c088b6d3e6282823dfb: Scheduling FlushMRSOp(bd02ca77f9ad4883803840dff3522252): perf score=1.000000
I20260812 06:20:35.144282 12647 maintenance_manager.cc:643] P eb02244d9bf14c088b6d3e6282823dfb: FlushMRSOp(bd02ca77f9ad4883803840dff3522252) complete. Timing: real 0.040s	user 0.028s	sys 0.000s Metrics: {"bytes_written":1234479,"cfile_init":1,"dirs.queue_time_us":83,"dirs.run_cpu_time_us":272,"dirs.run_wall_time_us":1630,"drs_written":1,"lbm_read_time_us":46,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1576,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:20:35.144923 12745 maintenance_manager.cc:419] P eb02244d9bf14c088b6d3e6282823dfb: Scheduling FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252): perf score=3.181125
I20260812 06:20:35.162135 12647 maintenance_manager.cc:643] P eb02244d9bf14c088b6d3e6282823dfb: FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252) complete. Timing: real 0.017s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4512901,"delete_count":0,"lbm_write_time_us":4318,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:35.162683 12745 maintenance_manager.cc:419] P eb02244d9bf14c088b6d3e6282823dfb: Scheduling LogGCOp(bd02ca77f9ad4883803840dff3522252): free 120553442 bytes of WAL
I20260812 06:20:35.162990 12647 log_reader.cc:385] T bd02ca77f9ad4883803840dff3522252: removed 12 log segments from log reader
I20260812 06:20:35.163049 12647 log.cc:1079] T bd02ca77f9ad4883803840dff3522252 P eb02244d9bf14c088b6d3e6282823dfb: Deleting log segment in path: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625276931-12225-0/minicluster-data/ts-0-root/wals/bd02ca77f9ad4883803840dff3522252/wal-000000015 (ops 72-76)
I20260812 06:20:35.163090 12647 log.cc:1079] T bd02ca77f9ad4883803840dff3522252 P eb02244d9bf14c088b6d3e6282823dfb: Deleting log segment in path: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625276931-12225-0/minicluster-data/ts-0-root/wals/bd02ca77f9ad4883803840dff3522252/wal-000000016 (ops 77-80)
I20260812 06:20:35.163121 12647 log.cc:1079] T bd02ca77f9ad4883803840dff3522252 P eb02244d9bf14c088b6d3e6282823dfb: Deleting log segment in path: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625276931-12225-0/minicluster-data/ts-0-root/wals/bd02ca77f9ad4883803840dff3522252/wal-000000017 (ops 81-85)
I20260812 06:20:35.163154 12647 log.cc:1079] T bd02ca77f9ad4883803840dff3522252 P eb02244d9bf14c088b6d3e6282823dfb: Deleting log segment in path: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625276931-12225-0/minicluster-data/ts-0-root/wals/bd02ca77f9ad4883803840dff3522252/wal-000000018 (ops 86-90)
I20260812 06:20:35.163188 12647 log.cc:1079] T bd02ca77f9ad4883803840dff3522252 P eb02244d9bf14c088b6d3e6282823dfb: Deleting log segment in path: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625276931-12225-0/minicluster-data/ts-0-root/wals/bd02ca77f9ad4883803840dff3522252/wal-000000019 (ops 91-95)
I20260812 06:20:35.163219 12647 log.cc:1079] T bd02ca77f9ad4883803840dff3522252 P eb02244d9bf14c088b6d3e6282823dfb: Deleting log segment in path: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625276931-12225-0/minicluster-data/ts-0-root/wals/bd02ca77f9ad4883803840dff3522252/wal-000000020 (ops 96-100)
I20260812 06:20:35.163249 12647 log.cc:1079] T bd02ca77f9ad4883803840dff3522252 P eb02244d9bf14c088b6d3e6282823dfb: Deleting log segment in path: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625276931-12225-0/minicluster-data/ts-0-root/wals/bd02ca77f9ad4883803840dff3522252/wal-000000021 (ops 101-105)
I20260812 06:20:35.163276 12647 log.cc:1079] T bd02ca77f9ad4883803840dff3522252 P eb02244d9bf14c088b6d3e6282823dfb: Deleting log segment in path: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625276931-12225-0/minicluster-data/ts-0-root/wals/bd02ca77f9ad4883803840dff3522252/wal-000000022 (ops 106-110)
I20260812 06:20:35.163306 12647 log.cc:1079] T bd02ca77f9ad4883803840dff3522252 P eb02244d9bf14c088b6d3e6282823dfb: Deleting log segment in path: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625276931-12225-0/minicluster-data/ts-0-root/wals/bd02ca77f9ad4883803840dff3522252/wal-000000023 (ops 111-115)
I20260812 06:20:35.163340 12647 log.cc:1079] T bd02ca77f9ad4883803840dff3522252 P eb02244d9bf14c088b6d3e6282823dfb: Deleting log segment in path: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625276931-12225-0/minicluster-data/ts-0-root/wals/bd02ca77f9ad4883803840dff3522252/wal-000000024 (ops 116-120)
I20260812 06:20:35.163374 12647 log.cc:1079] T bd02ca77f9ad4883803840dff3522252 P eb02244d9bf14c088b6d3e6282823dfb: Deleting log segment in path: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625276931-12225-0/minicluster-data/ts-0-root/wals/bd02ca77f9ad4883803840dff3522252/wal-000000025 (ops 121-124)
I20260812 06:20:35.163404 12647 log.cc:1079] T bd02ca77f9ad4883803840dff3522252 P eb02244d9bf14c088b6d3e6282823dfb: Deleting log segment in path: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625276931-12225-0/minicluster-data/ts-0-root/wals/bd02ca77f9ad4883803840dff3522252/wal-000000026 (ops 125-129)
I20260812 06:20:35.197288 12647 maintenance_manager.cc:643] P eb02244d9bf14c088b6d3e6282823dfb: LogGCOp(bd02ca77f9ad4883803840dff3522252) complete. Timing: real 0.034s	user 0.001s	sys 0.031s Metrics: {}
I20260812 06:20:35.197765 12745 maintenance_manager.cc:419] P eb02244d9bf14c088b6d3e6282823dfb: Scheduling UndoDeltaBlockGCOp(bd02ca77f9ad4883803840dff3522252): 473 bytes on disk
I20260812 06:20:35.198388 12647 maintenance_manager.cc:643] P eb02244d9bf14c088b6d3e6282823dfb: UndoDeltaBlockGCOp(bd02ca77f9ad4883803840dff3522252) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":82,"lbm_reads_lt_1ms":4}
I20260812 06:20:35.199081 12745 maintenance_manager.cc:419] P eb02244d9bf14c088b6d3e6282823dfb: Scheduling FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252): perf score=2.188937
I20260812 06:20:35.225234 12647 maintenance_manager.cc:643] P eb02244d9bf14c088b6d3e6282823dfb: FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252) complete. Timing: real 0.026s	user 0.006s	sys 0.009s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6921,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:35.225692 12745 maintenance_manager.cc:419] P eb02244d9bf14c088b6d3e6282823dfb: Scheduling FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252): perf score=2.188937
I20260812 06:20:35.236881 12647 maintenance_manager.cc:643] P eb02244d9bf14c088b6d3e6282823dfb: FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4386,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:35.237672 12745 maintenance_manager.cc:419] P eb02244d9bf14c088b6d3e6282823dfb: Scheduling MajorDeltaCompactionOp(bd02ca77f9ad4883803840dff3522252): perf score=1.000000
I20260812 06:20:35.441118 12647 maintenance_manager.cc:643] P eb02244d9bf14c088b6d3e6282823dfb: MajorDeltaCompactionOp(bd02ca77f9ad4883803840dff3522252) complete. Timing: real 0.203s	user 0.165s	sys 0.036s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877328,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":2548,"lbm_read_time_us":13767,"lbm_reads_lt_1ms":674,"lbm_write_time_us":40388,"lbm_writes_lt_1ms":643,"mutex_wait_us":1921,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":25472,"thread_start_us":91,"threads_started":1,"update_count":3000}
I20260812 06:20:35.441711 12745 maintenance_manager.cc:419] P eb02244d9bf14c088b6d3e6282823dfb: Scheduling FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252): perf score=14.095187
I20260812 06:20:35.504298 12647 maintenance_manager.cc:643] P eb02244d9bf14c088b6d3e6282823dfb: FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252) complete. Timing: real 0.062s	user 0.030s	sys 0.031s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":25072,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:35.504855 12745 maintenance_manager.cc:419] P eb02244d9bf14c088b6d3e6282823dfb: Scheduling FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252): perf score=2.188937
I20260812 06:20:35.523933 12647 maintenance_manager.cc:643] P eb02244d9bf14c088b6d3e6282823dfb: FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252) complete. Timing: real 0.019s	user 0.008s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4726,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:35.524380 12745 maintenance_manager.cc:419] P eb02244d9bf14c088b6d3e6282823dfb: Scheduling FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252): perf score=2.188937
I20260812 06:20:35.536168 12647 maintenance_manager.cc:643] P eb02244d9bf14c088b6d3e6282823dfb: FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252) complete. Timing: real 0.012s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4593,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:35.536625 12745 maintenance_manager.cc:419] P eb02244d9bf14c088b6d3e6282823dfb: Scheduling MajorDeltaCompactionOp(bd02ca77f9ad4883803840dff3522252): perf score=1.000000
I20260812 06:20:35.754696 12647 maintenance_manager.cc:643] P eb02244d9bf14c088b6d3e6282823dfb: MajorDeltaCompactionOp(bd02ca77f9ad4883803840dff3522252) complete. Timing: real 0.218s	user 0.151s	sys 0.057s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877218,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1292,"lbm_read_time_us":13649,"lbm_reads_lt_1ms":673,"lbm_write_time_us":34087,"lbm_writes_lt_1ms":643,"mutex_wait_us":23,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":11648,"update_count":3000}
I20260812 06:20:35.755636 12745 maintenance_manager.cc:419] P eb02244d9bf14c088b6d3e6282823dfb: Scheduling FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252): perf score=14.095187
I20260812 06:20:35.808166 12647 maintenance_manager.cc:643] P eb02244d9bf14c088b6d3e6282823dfb: FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252) complete. Timing: real 0.052s	user 0.014s	sys 0.035s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22111,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:35.808714 12745 maintenance_manager.cc:419] P eb02244d9bf14c088b6d3e6282823dfb: Scheduling FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252): perf score=2.188937
I20260812 06:20:35.835539 12647 maintenance_manager.cc:643] P eb02244d9bf14c088b6d3e6282823dfb: FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252) complete. Timing: real 0.027s	user 0.011s	sys 0.014s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6066,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:35.836109 12745 maintenance_manager.cc:419] P eb02244d9bf14c088b6d3e6282823dfb: Scheduling MajorDeltaCompactionOp(bd02ca77f9ad4883803840dff3522252): perf score=1.000000
I20260812 06:20:36.026145 12647 maintenance_manager.cc:643] P eb02244d9bf14c088b6d3e6282823dfb: MajorDeltaCompactionOp(bd02ca77f9ad4883803840dff3522252) complete. Timing: real 0.190s	user 0.093s	sys 0.096s 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":1149,"lbm_read_time_us":13906,"lbm_reads_lt_1ms":564,"lbm_write_time_us":30444,"lbm_writes_lt_1ms":543,"mutex_wait_us":32,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5248,"update_count":2500}
I20260812 06:20:36.027392 12745 maintenance_manager.cc:419] P eb02244d9bf14c088b6d3e6282823dfb: Scheduling FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252): perf score=14.095187
I20260812 06:20:36.072736 12647 maintenance_manager.cc:643] P eb02244d9bf14c088b6d3e6282823dfb: FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252) complete. Timing: real 0.045s	user 0.027s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20743,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:36.073227 12745 maintenance_manager.cc:419] P eb02244d9bf14c088b6d3e6282823dfb: Scheduling FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252): perf score=2.188937
I20260812 06:20:36.086993 12647 maintenance_manager.cc:643] P eb02244d9bf14c088b6d3e6282823dfb: FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252) complete. Timing: real 0.014s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5481,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:36.087491 12745 maintenance_manager.cc:419] P eb02244d9bf14c088b6d3e6282823dfb: Scheduling MajorDeltaCompactionOp(bd02ca77f9ad4883803840dff3522252): perf score=1.000000
I20260812 06:20:36.261322 12647 maintenance_manager.cc:643] P eb02244d9bf14c088b6d3e6282823dfb: MajorDeltaCompactionOp(bd02ca77f9ad4883803840dff3522252) complete. Timing: real 0.174s	user 0.142s	sys 0.029s 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":1378,"lbm_read_time_us":9702,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34813,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2500}
I20260812 06:20:36.262020 12745 maintenance_manager.cc:419] P eb02244d9bf14c088b6d3e6282823dfb: Scheduling FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252): perf score=11.118625
I20260812 06:20:36.320815 12647 maintenance_manager.cc:643] P eb02244d9bf14c088b6d3e6282823dfb: FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252) complete. Timing: real 0.059s	user 0.009s	sys 0.035s Metrics: {"bytes_written":12717739,"delete_count":0,"lbm_write_time_us":22310,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":311,"reinsert_count":0,"update_count":1550}
I20260812 06:20:36.321388 12745 maintenance_manager.cc:419] P eb02244d9bf14c088b6d3e6282823dfb: Scheduling FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252): perf score=6.157687
I20260812 06:20:36.351547 12647 maintenance_manager.cc:643] P eb02244d9bf14c088b6d3e6282823dfb: FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252) complete. Timing: real 0.030s	user 0.011s	sys 0.012s Metrics: {"bytes_written":7794836,"delete_count":0,"lbm_write_time_us":10280,"lbm_writes_lt_1ms":193,"reinsert_count":0,"update_count":950}
I20260812 06:20:36.352363 12745 maintenance_manager.cc:419] P eb02244d9bf14c088b6d3e6282823dfb: Scheduling MajorDeltaCompactionOp(bd02ca77f9ad4883803840dff3522252): perf score=1.000000
I20260812 06:20:36.514552 12647 maintenance_manager.cc:643] P eb02244d9bf14c088b6d3e6282823dfb: MajorDeltaCompactionOp(bd02ca77f9ad4883803840dff3522252) complete. Timing: real 0.162s	user 0.113s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774697,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":579,"lbm_read_time_us":11357,"lbm_reads_lt_1ms":564,"lbm_write_time_us":31809,"lbm_writes_lt_1ms":543,"mutex_wait_us":284,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":54016,"update_count":2500}
I20260812 06:20:36.515329 12745 maintenance_manager.cc:419] P eb02244d9bf14c088b6d3e6282823dfb: Scheduling FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252): perf score=14.095187
I20260812 06:20:36.567144 12647 maintenance_manager.cc:643] P eb02244d9bf14c088b6d3e6282823dfb: FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252) complete. Timing: real 0.051s	user 0.038s	sys 0.002s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":17610,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:36.567687 12745 maintenance_manager.cc:419] P eb02244d9bf14c088b6d3e6282823dfb: Scheduling FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252): perf score=2.188937
I20260812 06:20:36.579658 12647 maintenance_manager.cc:643] P eb02244d9bf14c088b6d3e6282823dfb: FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252) complete. Timing: real 0.012s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4607,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:36.580583 12745 maintenance_manager.cc:419] P eb02244d9bf14c088b6d3e6282823dfb: Scheduling FlushMRSOp(bd02ca77f9ad4883803840dff3522252): perf score=1.000000
I20260812 06:20:36.612645 12647 maintenance_manager.cc:643] P eb02244d9bf14c088b6d3e6282823dfb: FlushMRSOp(bd02ca77f9ad4883803840dff3522252) complete. Timing: real 0.032s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1152510,"cfile_init":1,"dirs.queue_time_us":119,"dirs.run_cpu_time_us":331,"dirs.run_wall_time_us":1275,"drs_written":1,"lbm_read_time_us":111,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2026,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:20:36.613306 12745 maintenance_manager.cc:419] P eb02244d9bf14c088b6d3e6282823dfb: Scheduling LogGCOp(bd02ca77f9ad4883803840dff3522252): free 112239502 bytes of WAL
I20260812 06:20:36.613528 12647 log_reader.cc:385] T bd02ca77f9ad4883803840dff3522252: removed 11 log segments from log reader
I20260812 06:20:36.613570 12647 log.cc:1079] T bd02ca77f9ad4883803840dff3522252 P eb02244d9bf14c088b6d3e6282823dfb: Deleting log segment in path: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625276931-12225-0/minicluster-data/ts-0-root/wals/bd02ca77f9ad4883803840dff3522252/wal-000000027 (ops 130-134)
I20260812 06:20:36.613600 12647 log.cc:1079] T bd02ca77f9ad4883803840dff3522252 P eb02244d9bf14c088b6d3e6282823dfb: Deleting log segment in path: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625276931-12225-0/minicluster-data/ts-0-root/wals/bd02ca77f9ad4883803840dff3522252/wal-000000028 (ops 135-139)
I20260812 06:20:36.613663 12647 log.cc:1079] T bd02ca77f9ad4883803840dff3522252 P eb02244d9bf14c088b6d3e6282823dfb: Deleting log segment in path: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625276931-12225-0/minicluster-data/ts-0-root/wals/bd02ca77f9ad4883803840dff3522252/wal-000000029 (ops 140-144)
I20260812 06:20:36.613724 12647 log.cc:1079] T bd02ca77f9ad4883803840dff3522252 P eb02244d9bf14c088b6d3e6282823dfb: Deleting log segment in path: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625276931-12225-0/minicluster-data/ts-0-root/wals/bd02ca77f9ad4883803840dff3522252/wal-000000030 (ops 145-148)
I20260812 06:20:36.613765 12647 log.cc:1079] T bd02ca77f9ad4883803840dff3522252 P eb02244d9bf14c088b6d3e6282823dfb: Deleting log segment in path: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625276931-12225-0/minicluster-data/ts-0-root/wals/bd02ca77f9ad4883803840dff3522252/wal-000000031 (ops 149-153)
I20260812 06:20:36.613807 12647 log.cc:1079] T bd02ca77f9ad4883803840dff3522252 P eb02244d9bf14c088b6d3e6282823dfb: Deleting log segment in path: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625276931-12225-0/minicluster-data/ts-0-root/wals/bd02ca77f9ad4883803840dff3522252/wal-000000032 (ops 154-158)
I20260812 06:20:36.613847 12647 log.cc:1079] T bd02ca77f9ad4883803840dff3522252 P eb02244d9bf14c088b6d3e6282823dfb: Deleting log segment in path: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625276931-12225-0/minicluster-data/ts-0-root/wals/bd02ca77f9ad4883803840dff3522252/wal-000000033 (ops 159-163)
I20260812 06:20:36.613893 12647 log.cc:1079] T bd02ca77f9ad4883803840dff3522252 P eb02244d9bf14c088b6d3e6282823dfb: Deleting log segment in path: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625276931-12225-0/minicluster-data/ts-0-root/wals/bd02ca77f9ad4883803840dff3522252/wal-000000034 (ops 164-168)
I20260812 06:20:36.613933 12647 log.cc:1079] T bd02ca77f9ad4883803840dff3522252 P eb02244d9bf14c088b6d3e6282823dfb: Deleting log segment in path: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625276931-12225-0/minicluster-data/ts-0-root/wals/bd02ca77f9ad4883803840dff3522252/wal-000000035 (ops 169-173)
I20260812 06:20:36.613971 12647 log.cc:1079] T bd02ca77f9ad4883803840dff3522252 P eb02244d9bf14c088b6d3e6282823dfb: Deleting log segment in path: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625276931-12225-0/minicluster-data/ts-0-root/wals/bd02ca77f9ad4883803840dff3522252/wal-000000036 (ops 174-178)
I20260812 06:20:36.614009 12647 log.cc:1079] T bd02ca77f9ad4883803840dff3522252 P eb02244d9bf14c088b6d3e6282823dfb: Deleting log segment in path: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625276931-12225-0/minicluster-data/ts-0-root/wals/bd02ca77f9ad4883803840dff3522252/wal-000000037 (ops 179-183)
I20260812 06:20:36.638022 12647 maintenance_manager.cc:643] P eb02244d9bf14c088b6d3e6282823dfb: LogGCOp(bd02ca77f9ad4883803840dff3522252) complete. Timing: real 0.025s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:20:36.638669 12745 maintenance_manager.cc:419] P eb02244d9bf14c088b6d3e6282823dfb: Scheduling UndoDeltaBlockGCOp(bd02ca77f9ad4883803840dff3522252): 447 bytes on disk
I20260812 06:20:36.639343 12647 maintenance_manager.cc:643] P eb02244d9bf14c088b6d3e6282823dfb: UndoDeltaBlockGCOp(bd02ca77f9ad4883803840dff3522252) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4}
I20260812 06:20:36.640240 12745 maintenance_manager.cc:419] P eb02244d9bf14c088b6d3e6282823dfb: Scheduling FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252): perf score=2.188937
I20260812 06:20:36.654713 12647 maintenance_manager.cc:643] P eb02244d9bf14c088b6d3e6282823dfb: FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252) complete. Timing: real 0.014s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4904,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:36.655138 12745 maintenance_manager.cc:419] P eb02244d9bf14c088b6d3e6282823dfb: Scheduling LogGCOp(bd02ca77f9ad4883803840dff3522252): free 12018006 bytes of WAL
I20260812 06:20:36.655326 12647 log_reader.cc:385] T bd02ca77f9ad4883803840dff3522252: removed 1 log segments from log reader
I20260812 06:20:36.655385 12647 log.cc:1079] T bd02ca77f9ad4883803840dff3522252 P eb02244d9bf14c088b6d3e6282823dfb: Deleting log segment in path: /tmp/dist-test-taskgK8Fex/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515625276931-12225-0/minicluster-data/ts-0-root/wals/bd02ca77f9ad4883803840dff3522252/wal-000000038 (ops 184-188)
I20260812 06:20:36.657809 12647 maintenance_manager.cc:643] P eb02244d9bf14c088b6d3e6282823dfb: LogGCOp(bd02ca77f9ad4883803840dff3522252) complete. Timing: real 0.003s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:20:36.658105 12745 maintenance_manager.cc:419] P eb02244d9bf14c088b6d3e6282823dfb: Scheduling FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252): perf score=2.188937
I20260812 06:20:36.671306 12647 maintenance_manager.cc:643] P eb02244d9bf14c088b6d3e6282823dfb: FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252) complete. Timing: real 0.013s	user 0.005s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4620,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:36.671790 12745 maintenance_manager.cc:419] P eb02244d9bf14c088b6d3e6282823dfb: Scheduling MajorDeltaCompactionOp(bd02ca77f9ad4883803840dff3522252): perf score=1.000000
I20260812 06:20:36.939208 12647 maintenance_manager.cc:643] P eb02244d9bf14c088b6d3e6282823dfb: MajorDeltaCompactionOp(bd02ca77f9ad4883803840dff3522252) complete. Timing: real 0.267s	user 0.191s	sys 0.066s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979752,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":122,"lbm_read_time_us":20098,"lbm_reads_lt_1ms":774,"lbm_write_time_us":41849,"lbm_writes_lt_1ms":743,"mutex_wait_us":23,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":11008,"thread_start_us":80,"threads_started":1,"update_count":3500}
I20260812 06:20:36.941561 12745 maintenance_manager.cc:419] P eb02244d9bf14c088b6d3e6282823dfb: Scheduling FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252): perf score=18.063937
I20260812 06:20:36.994335 12225 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.432s	user 1.935s	sys 0.220s
I20260812 06:20:37.007863 12647 maintenance_manager.cc:643] P eb02244d9bf14c088b6d3e6282823dfb: FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252) complete. Timing: real 0.066s	user 0.025s	sys 0.040s Metrics: {"bytes_written":20512318,"delete_count":0,"lbm_write_time_us":34431,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":500,"reinsert_count":0,"update_count":2500}
I20260812 06:20:37.008628 12745 maintenance_manager.cc:419] P eb02244d9bf14c088b6d3e6282823dfb: Scheduling FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252): perf score=2.188937
I20260812 06:20:37.019101 12647 maintenance_manager.cc:643] P eb02244d9bf14c088b6d3e6282823dfb: FlushDeltaMemStoresOp(bd02ca77f9ad4883803840dff3522252) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3987,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:37.020272 12745 maintenance_manager.cc:419] P eb02244d9bf14c088b6d3e6282823dfb: Scheduling MajorDeltaCompactionOp(bd02ca77f9ad4883803840dff3522252): perf score=1.000000
I20260812 06:20:37.055915 12225 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.061s	user 0.002s	sys 0.000s
I20260812 06:20:37.056465 12225 tablet_server.cc:179] TabletServer@127.11.240.65:0 shutting down...
I20260812 06:20:37.216362 12647 maintenance_manager.cc:643] P eb02244d9bf14c088b6d3e6282823dfb: MajorDeltaCompactionOp(bd02ca77f9ad4883803840dff3522252) complete. Timing: real 0.196s	user 0.119s	sys 0.073s Metrics: {"cfile_cache_hit":30,"cfile_cache_hit_bytes":4262390,"cfile_cache_miss":602,"cfile_cache_miss_bytes":24614714,"cfile_init":4,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":765,"lbm_read_time_us":13457,"lbm_reads_lt_1ms":618,"lbm_write_time_us":31274,"lbm_writes_lt_1ms":643,"mutex_wait_us":157,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":43264,"update_count":3000}
I20260812 06:20:37.217337 12225 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:37.217572 12225 tablet_replica.cc:333] T bd02ca77f9ad4883803840dff3522252 P eb02244d9bf14c088b6d3e6282823dfb: stopping tablet replica
I20260812 06:20:37.217717 12225 raft_consensus.cc:2243] T bd02ca77f9ad4883803840dff3522252 P eb02244d9bf14c088b6d3e6282823dfb [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:37.217905 12225 raft_consensus.cc:2272] T bd02ca77f9ad4883803840dff3522252 P eb02244d9bf14c088b6d3e6282823dfb [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:37.232959 12225 tablet_server.cc:196] TabletServer@127.11.240.65:0 shutdown complete.
I20260812 06:20:37.271392 12225 master.cc:562] Master@127.11.240.126:37381 shutting down...
I20260812 06:20:37.275876 12225 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 4741a74d2cf54592bb14d4dba714266f [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:37.276095 12225 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 4741a74d2cf54592bb14d4dba714266f [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:37.276185 12225 tablet_replica.cc:333] T 00000000000000000000000000000000 P 4741a74d2cf54592bb14d4dba714266f: stopping tablet replica
I20260812 06:20:37.289278 12225 master.cc:584] Master@127.11.240.126:37381 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (6096 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (12098 ms total)

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