[==========] 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:18.886857 13552 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.13.60.62:39259
I20260812 06:20:18.888016 13552 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:18.888670 13552 file_cache.cc:504] Constructed file cache file cache with capacity 419430
I20260812 06:20:18.896118 13552 server_base.cc:1061] running on GCE node
W20260812 06:20:18.896054 13557 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:18.896054 13562 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:18.896595 13558 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:18.897166 13552 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:18.897310 13552 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:18.897362 13552 hybrid_clock.cc:648] HybridClock initialized: now 1786515618897359 us; error 0 us; skew 500 ppm
I20260812 06:20:18.899406 13552 webserver.cc:533] Webserver started at http://127.13.60.62:43217/ using document root <none> and password file <none>
I20260812 06:20:18.900079 13552 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:18.900190 13552 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:18.900463 13552 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:18.902360 13552 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618875398-13552-0/minicluster-data/master-0-root/instance:
uuid: "0e98853c48bf48d6b2b488c531018c90"
format_stamp: "Formatted at 2026-08-12 06:20:18 on dist-test-slave-fd7l"
I20260812 06:20:18.906459 13552 fs_manager.cc:696] Time spent creating directory manager: real 0.004s	user 0.005s	sys 0.000s
I20260812 06:20:18.908947 13567 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:18.910202 13552 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:20:18.910363 13552 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618875398-13552-0/minicluster-data/master-0-root
uuid: "0e98853c48bf48d6b2b488c531018c90"
format_stamp: "Formatted at 2026-08-12 06:20:18 on dist-test-slave-fd7l"
I20260812 06:20:18.910486 13552 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618875398-13552-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618875398-13552-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618875398-13552-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:18.941215 13552 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:18.941957 13552 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:18.942181 13552 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:18.950838 13629 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.13.60.62:39259 every 8 connection(s)
I20260812 06:20:18.950835 13552 rpc_server.cc:307] RPC server started. Bound to: 127.13.60.62:39259
I20260812 06:20:18.953617 13630 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:18.959688 13630 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 0e98853c48bf48d6b2b488c531018c90: Bootstrap starting.
I20260812 06:20:18.962337 13630 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 0e98853c48bf48d6b2b488c531018c90: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:18.963415 13630 log.cc:826] T 00000000000000000000000000000000 P 0e98853c48bf48d6b2b488c531018c90: Log is configured to *not* fsync() on all Append() calls
I20260812 06:20:18.965764 13630 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 0e98853c48bf48d6b2b488c531018c90: No bootstrap required, opened a new log
I20260812 06:20:18.969139 13630 raft_consensus.cc:359] T 00000000000000000000000000000000 P 0e98853c48bf48d6b2b488c531018c90 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0e98853c48bf48d6b2b488c531018c90" member_type: VOTER }
I20260812 06:20:18.969394 13630 raft_consensus.cc:385] T 00000000000000000000000000000000 P 0e98853c48bf48d6b2b488c531018c90 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:18.969445 13630 raft_consensus.cc:740] T 00000000000000000000000000000000 P 0e98853c48bf48d6b2b488c531018c90 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 0e98853c48bf48d6b2b488c531018c90, State: Initialized, Role: FOLLOWER
I20260812 06:20:18.970109 13630 consensus_queue.cc:260] T 00000000000000000000000000000000 P 0e98853c48bf48d6b2b488c531018c90 [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: "0e98853c48bf48d6b2b488c531018c90" member_type: VOTER }
I20260812 06:20:18.970280 13630 raft_consensus.cc:399] T 00000000000000000000000000000000 P 0e98853c48bf48d6b2b488c531018c90 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:18.970329 13630 raft_consensus.cc:493] T 00000000000000000000000000000000 P 0e98853c48bf48d6b2b488c531018c90 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:18.970427 13630 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 0e98853c48bf48d6b2b488c531018c90 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:18.971438 13630 raft_consensus.cc:515] T 00000000000000000000000000000000 P 0e98853c48bf48d6b2b488c531018c90 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0e98853c48bf48d6b2b488c531018c90" member_type: VOTER }
I20260812 06:20:18.971920 13630 leader_election.cc:304] T 00000000000000000000000000000000 P 0e98853c48bf48d6b2b488c531018c90 [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: 0e98853c48bf48d6b2b488c531018c90; no voters: 
I20260812 06:20:18.972301 13630 leader_election.cc:290] T 00000000000000000000000000000000 P 0e98853c48bf48d6b2b488c531018c90 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:18.972419 13633 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 0e98853c48bf48d6b2b488c531018c90 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:18.972790 13633 raft_consensus.cc:697] T 00000000000000000000000000000000 P 0e98853c48bf48d6b2b488c531018c90 [term 1 LEADER]: Becoming Leader. State: Replica: 0e98853c48bf48d6b2b488c531018c90, State: Running, Role: LEADER
I20260812 06:20:18.973295 13633 consensus_queue.cc:237] T 00000000000000000000000000000000 P 0e98853c48bf48d6b2b488c531018c90 [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: "0e98853c48bf48d6b2b488c531018c90" member_type: VOTER }
I20260812 06:20:18.973706 13630 sys_catalog.cc:565] T 00000000000000000000000000000000 P 0e98853c48bf48d6b2b488c531018c90 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:18.975519 13635 sys_catalog.cc:455] T 00000000000000000000000000000000 P 0e98853c48bf48d6b2b488c531018c90 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "0e98853c48bf48d6b2b488c531018c90" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0e98853c48bf48d6b2b488c531018c90" member_type: VOTER } }
I20260812 06:20:18.975544 13634 sys_catalog.cc:455] T 00000000000000000000000000000000 P 0e98853c48bf48d6b2b488c531018c90 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 0e98853c48bf48d6b2b488c531018c90. Latest consensus state: current_term: 1 leader_uuid: "0e98853c48bf48d6b2b488c531018c90" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0e98853c48bf48d6b2b488c531018c90" member_type: VOTER } }
I20260812 06:20:18.975680 13634 sys_catalog.cc:458] T 00000000000000000000000000000000 P 0e98853c48bf48d6b2b488c531018c90 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:18.975679 13635 sys_catalog.cc:458] T 00000000000000000000000000000000 P 0e98853c48bf48d6b2b488c531018c90 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:18.976090 13643 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:18.978856 13643 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:18.979172 13552 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:18.984623 13643 catalog_manager.cc:1383] Generated new cluster ID: ef95f3ab7af0493a8e94d50657b8417b
I20260812 06:20:18.984755 13643 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:19.005388 13643 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:19.007058 13643 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:19.019874 13643 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 0e98853c48bf48d6b2b488c531018c90: Generated new TSK 0
I20260812 06:20:19.020758 13643 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:19.044919 13552 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:19.048658 13656 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:19.048744 13658 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:19.048897 13655 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:19.049001 13552 server_base.cc:1061] running on GCE node
I20260812 06:20:19.049269 13552 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:19.049338 13552 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:19.049365 13552 hybrid_clock.cc:648] HybridClock initialized: now 1786515619049365 us; error 0 us; skew 500 ppm
I20260812 06:20:19.050482 13552 webserver.cc:533] Webserver started at http://127.13.60.1:32881/ using document root <none> and password file <none>
I20260812 06:20:19.050670 13552 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:19.050734 13552 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:19.050818 13552 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:19.051309 13552 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618875398-13552-0/minicluster-data/ts-0-root/instance:
uuid: "a1dff8a625984f11bc6111abf7ac5385"
format_stamp: "Formatted at 2026-08-12 06:20:19 on dist-test-slave-fd7l"
I20260812 06:20:19.053431 13552 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:20:19.054924 13665 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:19.055277 13552 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:19.055356 13552 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618875398-13552-0/minicluster-data/ts-0-root
uuid: "a1dff8a625984f11bc6111abf7ac5385"
format_stamp: "Formatted at 2026-08-12 06:20:19 on dist-test-slave-fd7l"
I20260812 06:20:19.055490 13552 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618875398-13552-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618875398-13552-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618875398-13552-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:19.088639 13552 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:19.089174 13552 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:19.089720 13552 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:19.090713 13552 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:19.090792 13552 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:19.090873 13552 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:19.090916 13552 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:19.098291 13552 rpc_server.cc:307] RPC server started. Bound to: 127.13.60.1:43147
I20260812 06:20:19.098338 13733 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.13.60.1:43147 every 8 connection(s)
I20260812 06:20:19.113682 13734 heartbeater.cc:344] Connected to a master server at 127.13.60.62:39259
I20260812 06:20:19.114007 13734 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:19.114709 13734 heartbeater.cc:507] Master 127.13.60.62:39259 requested a full tablet report, sending...
I20260812 06:20:19.116782 13586 ts_manager.cc:194] Registered new tserver with Master: a1dff8a625984f11bc6111abf7ac5385 (127.13.60.1:43147)
I20260812 06:20:19.117019 13552 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.018012137s
I20260812 06:20:19.118585 13586 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:52032
I20260812 06:20:19.130266 13586 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:52036:
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:19.147807 13696 tablet_service.cc:1511] Processing CreateTablet for tablet 2e47d2951d0646958a35d9fe6b791aeb (DEFAULT_TABLE table=heavy-update-compaction-test [id=e657fd81cd9345c492964bdd19d0bcbf]), partition=
I20260812 06:20:19.148389 13696 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 2e47d2951d0646958a35d9fe6b791aeb. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:19.151894 13750 tablet_bootstrap.cc:492] T 2e47d2951d0646958a35d9fe6b791aeb P a1dff8a625984f11bc6111abf7ac5385: Bootstrap starting.
I20260812 06:20:19.153368 13750 tablet_bootstrap.cc:654] T 2e47d2951d0646958a35d9fe6b791aeb P a1dff8a625984f11bc6111abf7ac5385: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:19.154914 13750 tablet_bootstrap.cc:492] T 2e47d2951d0646958a35d9fe6b791aeb P a1dff8a625984f11bc6111abf7ac5385: No bootstrap required, opened a new log
I20260812 06:20:19.155112 13750 ts_tablet_manager.cc:1403] T 2e47d2951d0646958a35d9fe6b791aeb P a1dff8a625984f11bc6111abf7ac5385: Time spent bootstrapping tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:20:19.155777 13750 raft_consensus.cc:359] T 2e47d2951d0646958a35d9fe6b791aeb P a1dff8a625984f11bc6111abf7ac5385 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a1dff8a625984f11bc6111abf7ac5385" member_type: VOTER last_known_addr { host: "127.13.60.1" port: 43147 } }
I20260812 06:20:19.155939 13750 raft_consensus.cc:385] T 2e47d2951d0646958a35d9fe6b791aeb P a1dff8a625984f11bc6111abf7ac5385 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:19.156013 13750 raft_consensus.cc:740] T 2e47d2951d0646958a35d9fe6b791aeb P a1dff8a625984f11bc6111abf7ac5385 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: a1dff8a625984f11bc6111abf7ac5385, State: Initialized, Role: FOLLOWER
I20260812 06:20:19.156174 13750 consensus_queue.cc:260] T 2e47d2951d0646958a35d9fe6b791aeb P a1dff8a625984f11bc6111abf7ac5385 [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: "a1dff8a625984f11bc6111abf7ac5385" member_type: VOTER last_known_addr { host: "127.13.60.1" port: 43147 } }
I20260812 06:20:19.156292 13750 raft_consensus.cc:399] T 2e47d2951d0646958a35d9fe6b791aeb P a1dff8a625984f11bc6111abf7ac5385 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:19.156347 13750 raft_consensus.cc:493] T 2e47d2951d0646958a35d9fe6b791aeb P a1dff8a625984f11bc6111abf7ac5385 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:19.156406 13750 raft_consensus.cc:3060] T 2e47d2951d0646958a35d9fe6b791aeb P a1dff8a625984f11bc6111abf7ac5385 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:19.157632 13750 raft_consensus.cc:515] T 2e47d2951d0646958a35d9fe6b791aeb P a1dff8a625984f11bc6111abf7ac5385 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a1dff8a625984f11bc6111abf7ac5385" member_type: VOTER last_known_addr { host: "127.13.60.1" port: 43147 } }
I20260812 06:20:19.157809 13750 leader_election.cc:304] T 2e47d2951d0646958a35d9fe6b791aeb P a1dff8a625984f11bc6111abf7ac5385 [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: a1dff8a625984f11bc6111abf7ac5385; no voters: 
I20260812 06:20:19.158102 13750 leader_election.cc:290] T 2e47d2951d0646958a35d9fe6b791aeb P a1dff8a625984f11bc6111abf7ac5385 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:19.158310 13752 raft_consensus.cc:2804] T 2e47d2951d0646958a35d9fe6b791aeb P a1dff8a625984f11bc6111abf7ac5385 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:19.158545 13750 ts_tablet_manager.cc:1434] T 2e47d2951d0646958a35d9fe6b791aeb P a1dff8a625984f11bc6111abf7ac5385: Time spent starting tablet: real 0.003s	user 0.000s	sys 0.003s
I20260812 06:20:19.158607 13752 raft_consensus.cc:697] T 2e47d2951d0646958a35d9fe6b791aeb P a1dff8a625984f11bc6111abf7ac5385 [term 1 LEADER]: Becoming Leader. State: Replica: a1dff8a625984f11bc6111abf7ac5385, State: Running, Role: LEADER
I20260812 06:20:19.158823 13734 heartbeater.cc:499] Master 127.13.60.62:39259 was elected leader, sending a full tablet report...
I20260812 06:20:19.158891 13752 consensus_queue.cc:237] T 2e47d2951d0646958a35d9fe6b791aeb P a1dff8a625984f11bc6111abf7ac5385 [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: "a1dff8a625984f11bc6111abf7ac5385" member_type: VOTER last_known_addr { host: "127.13.60.1" port: 43147 } }
I20260812 06:20:19.162278 13586 catalog_manager.cc:5719] T 2e47d2951d0646958a35d9fe6b791aeb P a1dff8a625984f11bc6111abf7ac5385 reported cstate change: term changed from 0 to 1, leader changed from <none> to a1dff8a625984f11bc6111abf7ac5385 (127.13.60.1). New cstate: current_term: 1 leader_uuid: "a1dff8a625984f11bc6111abf7ac5385" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a1dff8a625984f11bc6111abf7ac5385" member_type: VOTER last_known_addr { host: "127.13.60.1" port: 43147 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:19.232709 13552 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.063s	user 0.026s	sys 0.003s
I20260812 06:20:19.349622 13735 maintenance_manager.cc:419] P a1dff8a625984f11bc6111abf7ac5385: Scheduling FlushMRSOp(2e47d2951d0646958a35d9fe6b791aeb): perf score=15.086190
I20260812 06:20:19.517211 13670 maintenance_manager.cc:643] P a1dff8a625984f11bc6111abf7ac5385: FlushMRSOp(2e47d2951d0646958a35d9fe6b791aeb) complete. Timing: real 0.167s	user 0.133s	sys 0.032s Metrics: {"bytes_written":12307491,"cfile_init":1,"compiler_manager_pool.queue_time_us":276,"delete_count":0,"dirs.queue_time_us":67,"dirs.run_cpu_time_us":252,"dirs.run_wall_time_us":974,"drs_written":1,"lbm_read_time_us":77,"lbm_reads_lt_1ms":4,"lbm_write_time_us":41181,"lbm_writes_lt_1ms":657,"peak_mem_usage":0,"reinsert_count":0,"rows_written":103,"thread_start_us":182,"threads_started":1,"update_count":1500}
I20260812 06:20:19.518556 13735 maintenance_manager.cc:419] P a1dff8a625984f11bc6111abf7ac5385: Scheduling LogGCOp(2e47d2951d0646958a35d9fe6b791aeb): free 11976772 bytes of WAL
I20260812 06:20:19.518877 13670 log_reader.cc:385] T 2e47d2951d0646958a35d9fe6b791aeb: removed 1 log segments from log reader
I20260812 06:20:19.518936 13670 log.cc:1079] T 2e47d2951d0646958a35d9fe6b791aeb P a1dff8a625984f11bc6111abf7ac5385: Deleting log segment in path: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618875398-13552-0/minicluster-data/ts-0-root/wals/2e47d2951d0646958a35d9fe6b791aeb/wal-000000001 (ops 1-6)
I20260812 06:20:19.522192 13670 maintenance_manager.cc:643] P a1dff8a625984f11bc6111abf7ac5385: LogGCOp(2e47d2951d0646958a35d9fe6b791aeb) complete. Timing: real 0.003s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:20:19.522593 13735 maintenance_manager.cc:419] P a1dff8a625984f11bc6111abf7ac5385: Scheduling FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb): perf score=2.188937
I20260812 06:20:19.537171 13670 maintenance_manager.cc:643] P a1dff8a625984f11bc6111abf7ac5385: FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb) complete. Timing: real 0.014s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5727,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:19.537693 13735 maintenance_manager.cc:419] P a1dff8a625984f11bc6111abf7ac5385: Scheduling MajorDeltaCompactionOp(2e47d2951d0646958a35d9fe6b791aeb): perf score=1.000000
I20260812 06:20:19.679627 13670 maintenance_manager.cc:643] P a1dff8a625984f11bc6111abf7ac5385: MajorDeltaCompactionOp(2e47d2951d0646958a35d9fe6b791aeb) complete. Timing: real 0.142s	user 0.110s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631313,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":967,"lbm_read_time_us":9451,"lbm_reads_lt_1ms":468,"lbm_write_time_us":27256,"lbm_writes_lt_1ms":443,"mutex_wait_us":23,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":14720,"thread_start_us":331,"threads_started":5,"update_count":2000}
I20260812 06:20:19.680333 13735 maintenance_manager.cc:419] P a1dff8a625984f11bc6111abf7ac5385: Scheduling FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb): perf score=10.126437
I20260812 06:20:19.719120 13670 maintenance_manager.cc:643] P a1dff8a625984f11bc6111abf7ac5385: FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb) complete. Timing: real 0.039s	user 0.019s	sys 0.017s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":16962,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:19.719683 13735 maintenance_manager.cc:419] P a1dff8a625984f11bc6111abf7ac5385: Scheduling FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb): perf score=2.188937
I20260812 06:20:19.734067 13670 maintenance_manager.cc:643] P a1dff8a625984f11bc6111abf7ac5385: FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb) complete. Timing: real 0.014s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5348,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:19.734649 13735 maintenance_manager.cc:419] P a1dff8a625984f11bc6111abf7ac5385: Scheduling MajorDeltaCompactionOp(2e47d2951d0646958a35d9fe6b791aeb): perf score=1.000000
I20260812 06:20:19.879868 13670 maintenance_manager.cc:643] P a1dff8a625984f11bc6111abf7ac5385: MajorDeltaCompactionOp(2e47d2951d0646958a35d9fe6b791aeb) complete. Timing: real 0.145s	user 0.121s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":377,"lbm_read_time_us":8921,"lbm_reads_lt_1ms":472,"lbm_write_time_us":30587,"lbm_writes_lt_1ms":443,"mutex_wait_us":73,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":13440,"update_count":2000}
I20260812 06:20:19.880800 13735 maintenance_manager.cc:419] P a1dff8a625984f11bc6111abf7ac5385: Scheduling UndoDeltaBlockGCOp(2e47d2951d0646958a35d9fe6b791aeb): 12308959 bytes on disk
I20260812 06:20:19.881278 13670 maintenance_manager.cc:643] P a1dff8a625984f11bc6111abf7ac5385: UndoDeltaBlockGCOp(2e47d2951d0646958a35d9fe6b791aeb) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":45,"lbm_reads_lt_1ms":4}
I20260812 06:20:19.881721 13735 maintenance_manager.cc:419] P a1dff8a625984f11bc6111abf7ac5385: Scheduling FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb): perf score=11.118625
I20260812 06:20:19.920183 13670 maintenance_manager.cc:643] P a1dff8a625984f11bc6111abf7ac5385: FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb) complete. Timing: real 0.038s	user 0.010s	sys 0.025s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":16447,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:19.920758 13735 maintenance_manager.cc:419] P a1dff8a625984f11bc6111abf7ac5385: Scheduling FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb): perf score=2.188937
I20260812 06:20:19.937322 13670 maintenance_manager.cc:643] P a1dff8a625984f11bc6111abf7ac5385: FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb) complete. Timing: real 0.016s	user 0.011s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4352,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:19.937969 13735 maintenance_manager.cc:419] P a1dff8a625984f11bc6111abf7ac5385: Scheduling MajorDeltaCompactionOp(2e47d2951d0646958a35d9fe6b791aeb): perf score=1.000000
I20260812 06:20:20.078894 13670 maintenance_manager.cc:643] P a1dff8a625984f11bc6111abf7ac5385: MajorDeltaCompactionOp(2e47d2951d0646958a35d9fe6b791aeb) complete. Timing: real 0.141s	user 0.113s	sys 0.022s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631303,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":380,"lbm_read_time_us":9742,"lbm_reads_lt_1ms":464,"lbm_write_time_us":27435,"lbm_writes_lt_1ms":443,"mutex_wait_us":74,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":13056,"update_count":2000}
I20260812 06:20:20.079533 13735 maintenance_manager.cc:419] P a1dff8a625984f11bc6111abf7ac5385: Scheduling FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb): perf score=11.118625
I20260812 06:20:20.127104 13670 maintenance_manager.cc:643] P a1dff8a625984f11bc6111abf7ac5385: FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb) complete. Timing: real 0.047s	user 0.023s	sys 0.019s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":16529,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:20.127785 13735 maintenance_manager.cc:419] P a1dff8a625984f11bc6111abf7ac5385: Scheduling FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb): perf score=3.181125
I20260812 06:20:20.141085 13670 maintenance_manager.cc:643] P a1dff8a625984f11bc6111abf7ac5385: FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb) complete. Timing: real 0.013s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4800070,"delete_count":0,"lbm_write_time_us":5258,"lbm_writes_lt_1ms":120,"reinsert_count":0,"update_count":585}
I20260812 06:20:20.141610 13735 maintenance_manager.cc:419] P a1dff8a625984f11bc6111abf7ac5385: Scheduling FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb): perf score=1.196750
I20260812 06:20:20.151062 13670 maintenance_manager.cc:643] P a1dff8a625984f11bc6111abf7ac5385: FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb) complete. Timing: real 0.009s	user 0.004s	sys 0.003s Metrics: {"bytes_written":2994980,"delete_count":0,"lbm_write_time_us":3566,"lbm_writes_lt_1ms":76,"reinsert_count":0,"update_count":365}
I20260812 06:20:20.151623 13735 maintenance_manager.cc:419] P a1dff8a625984f11bc6111abf7ac5385: Scheduling MajorDeltaCompactionOp(2e47d2951d0646958a35d9fe6b791aeb): perf score=1.000000
I20260812 06:20:20.329173 13670 maintenance_manager.cc:643] P a1dff8a625984f11bc6111abf7ac5385: MajorDeltaCompactionOp(2e47d2951d0646958a35d9fe6b791aeb) complete. Timing: real 0.177s	user 0.118s	sys 0.056s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24733820,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":7468,"lbm_read_time_us":12655,"lbm_reads_lt_1ms":573,"lbm_write_time_us":31556,"lbm_writes_lt_1ms":543,"mutex_wait_us":3407,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7296,"update_count":2500}
I20260812 06:20:20.330130 13735 maintenance_manager.cc:419] P a1dff8a625984f11bc6111abf7ac5385: Scheduling FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb): perf score=11.118625
I20260812 06:20:20.381687 13670 maintenance_manager.cc:643] P a1dff8a625984f11bc6111abf7ac5385: FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb) complete. Timing: real 0.051s	user 0.026s	sys 0.024s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":24769,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":310,"reinsert_count":0,"update_count":1550}
I20260812 06:20:20.382212 13735 maintenance_manager.cc:419] P a1dff8a625984f11bc6111abf7ac5385: Scheduling FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb): perf score=2.188937
I20260812 06:20:20.409703 13670 maintenance_manager.cc:643] P a1dff8a625984f11bc6111abf7ac5385: FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb) complete. Timing: real 0.027s	user 0.010s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4788,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:20.410300 13735 maintenance_manager.cc:419] P a1dff8a625984f11bc6111abf7ac5385: Scheduling FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb): perf score=2.188937
I20260812 06:20:20.426227 13670 maintenance_manager.cc:643] P a1dff8a625984f11bc6111abf7ac5385: FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb) complete. Timing: real 0.016s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6187,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:20.426930 13735 maintenance_manager.cc:419] P a1dff8a625984f11bc6111abf7ac5385: Scheduling MajorDeltaCompactionOp(2e47d2951d0646958a35d9fe6b791aeb): perf score=1.000000
I20260812 06:20:20.626362 13670 maintenance_manager.cc:643] P a1dff8a625984f11bc6111abf7ac5385: MajorDeltaCompactionOp(2e47d2951d0646958a35d9fe6b791aeb) complete. Timing: real 0.199s	user 0.115s	sys 0.078s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24733833,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":843,"lbm_read_time_us":13908,"lbm_reads_lt_1ms":573,"lbm_write_time_us":34475,"lbm_writes_lt_1ms":543,"mutex_wait_us":350,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:20:20.626950 13735 maintenance_manager.cc:419] P a1dff8a625984f11bc6111abf7ac5385: Scheduling FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb): perf score=14.095187
I20260812 06:20:20.695485 13670 maintenance_manager.cc:643] P a1dff8a625984f11bc6111abf7ac5385: FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb) complete. Timing: real 0.068s	user 0.041s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":24325,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:20.696197 13735 maintenance_manager.cc:419] P a1dff8a625984f11bc6111abf7ac5385: Scheduling FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb): perf score=2.188937
I20260812 06:20:20.714705 13670 maintenance_manager.cc:643] P a1dff8a625984f11bc6111abf7ac5385: FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb) complete. Timing: real 0.018s	user 0.012s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6925,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:20.715482 13735 maintenance_manager.cc:419] P a1dff8a625984f11bc6111abf7ac5385: Scheduling MajorDeltaCompactionOp(2e47d2951d0646958a35d9fe6b791aeb): perf score=1.000000
I20260812 06:20:20.922572 13670 maintenance_manager.cc:643] P a1dff8a625984f11bc6111abf7ac5385: MajorDeltaCompactionOp(2e47d2951d0646958a35d9fe6b791aeb) complete. Timing: real 0.207s	user 0.135s	sys 0.060s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733724,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1274,"lbm_read_time_us":16004,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31541,"lbm_writes_lt_1ms":543,"mutex_wait_us":354,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2048,"update_count":2500}
I20260812 06:20:20.923112 13735 maintenance_manager.cc:419] P a1dff8a625984f11bc6111abf7ac5385: Scheduling FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb): perf score=14.095187
I20260812 06:20:20.976366 13670 maintenance_manager.cc:643] P a1dff8a625984f11bc6111abf7ac5385: FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb) complete. Timing: real 0.053s	user 0.018s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20024,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:20.976939 13735 maintenance_manager.cc:419] P a1dff8a625984f11bc6111abf7ac5385: Scheduling FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb): perf score=2.188937
I20260812 06:20:20.993706 13670 maintenance_manager.cc:643] P a1dff8a625984f11bc6111abf7ac5385: FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb) complete. Timing: real 0.017s	user 0.010s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6400,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:20.994247 13735 maintenance_manager.cc:419] P a1dff8a625984f11bc6111abf7ac5385: Scheduling FlushMRSOp(2e47d2951d0646958a35d9fe6b791aeb): perf score=1.000000
I20260812 06:20:21.038667 13670 maintenance_manager.cc:643] P a1dff8a625984f11bc6111abf7ac5385: FlushMRSOp(2e47d2951d0646958a35d9fe6b791aeb) complete. Timing: real 0.044s	user 0.034s	sys 0.004s Metrics: {"bytes_written":1316414,"cfile_init":1,"dirs.queue_time_us":99,"dirs.run_cpu_time_us":293,"dirs.run_wall_time_us":1679,"drs_written":1,"lbm_read_time_us":68,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2149,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32,"spinlock_wait_cycles":2304}
I20260812 06:20:21.039584 13735 maintenance_manager.cc:419] P a1dff8a625984f11bc6111abf7ac5385: Scheduling LogGCOp(2e47d2951d0646958a35d9fe6b791aeb): free 129320496 bytes of WAL
I20260812 06:20:21.039851 13670 log_reader.cc:385] T 2e47d2951d0646958a35d9fe6b791aeb: removed 13 log segments from log reader
I20260812 06:20:21.039911 13670 log.cc:1079] T 2e47d2951d0646958a35d9fe6b791aeb P a1dff8a625984f11bc6111abf7ac5385: Deleting log segment in path: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618875398-13552-0/minicluster-data/ts-0-root/wals/2e47d2951d0646958a35d9fe6b791aeb/wal-000000002 (ops 7-11)
I20260812 06:20:21.039973 13670 log.cc:1079] T 2e47d2951d0646958a35d9fe6b791aeb P a1dff8a625984f11bc6111abf7ac5385: Deleting log segment in path: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618875398-13552-0/minicluster-data/ts-0-root/wals/2e47d2951d0646958a35d9fe6b791aeb/wal-000000003 (ops 12-16)
I20260812 06:20:21.040030 13670 log.cc:1079] T 2e47d2951d0646958a35d9fe6b791aeb P a1dff8a625984f11bc6111abf7ac5385: Deleting log segment in path: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618875398-13552-0/minicluster-data/ts-0-root/wals/2e47d2951d0646958a35d9fe6b791aeb/wal-000000004 (ops 17-20)
I20260812 06:20:21.040076 13670 log.cc:1079] T 2e47d2951d0646958a35d9fe6b791aeb P a1dff8a625984f11bc6111abf7ac5385: Deleting log segment in path: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618875398-13552-0/minicluster-data/ts-0-root/wals/2e47d2951d0646958a35d9fe6b791aeb/wal-000000005 (ops 21-25)
I20260812 06:20:21.040125 13670 log.cc:1079] T 2e47d2951d0646958a35d9fe6b791aeb P a1dff8a625984f11bc6111abf7ac5385: Deleting log segment in path: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618875398-13552-0/minicluster-data/ts-0-root/wals/2e47d2951d0646958a35d9fe6b791aeb/wal-000000006 (ops 26-30)
I20260812 06:20:21.040170 13670 log.cc:1079] T 2e47d2951d0646958a35d9fe6b791aeb P a1dff8a625984f11bc6111abf7ac5385: Deleting log segment in path: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618875398-13552-0/minicluster-data/ts-0-root/wals/2e47d2951d0646958a35d9fe6b791aeb/wal-000000007 (ops 31-35)
I20260812 06:20:21.040217 13670 log.cc:1079] T 2e47d2951d0646958a35d9fe6b791aeb P a1dff8a625984f11bc6111abf7ac5385: Deleting log segment in path: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618875398-13552-0/minicluster-data/ts-0-root/wals/2e47d2951d0646958a35d9fe6b791aeb/wal-000000008 (ops 36-40)
I20260812 06:20:21.040275 13670 log.cc:1079] T 2e47d2951d0646958a35d9fe6b791aeb P a1dff8a625984f11bc6111abf7ac5385: Deleting log segment in path: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618875398-13552-0/minicluster-data/ts-0-root/wals/2e47d2951d0646958a35d9fe6b791aeb/wal-000000009 (ops 41-45)
I20260812 06:20:21.040320 13670 log.cc:1079] T 2e47d2951d0646958a35d9fe6b791aeb P a1dff8a625984f11bc6111abf7ac5385: Deleting log segment in path: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618875398-13552-0/minicluster-data/ts-0-root/wals/2e47d2951d0646958a35d9fe6b791aeb/wal-000000010 (ops 46-50)
I20260812 06:20:21.040364 13670 log.cc:1079] T 2e47d2951d0646958a35d9fe6b791aeb P a1dff8a625984f11bc6111abf7ac5385: Deleting log segment in path: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618875398-13552-0/minicluster-data/ts-0-root/wals/2e47d2951d0646958a35d9fe6b791aeb/wal-000000011 (ops 51-54)
I20260812 06:20:21.040414 13670 log.cc:1079] T 2e47d2951d0646958a35d9fe6b791aeb P a1dff8a625984f11bc6111abf7ac5385: Deleting log segment in path: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618875398-13552-0/minicluster-data/ts-0-root/wals/2e47d2951d0646958a35d9fe6b791aeb/wal-000000012 (ops 55-59)
I20260812 06:20:21.040462 13670 log.cc:1079] T 2e47d2951d0646958a35d9fe6b791aeb P a1dff8a625984f11bc6111abf7ac5385: Deleting log segment in path: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618875398-13552-0/minicluster-data/ts-0-root/wals/2e47d2951d0646958a35d9fe6b791aeb/wal-000000013 (ops 60-64)
I20260812 06:20:21.040532 13670 log.cc:1079] T 2e47d2951d0646958a35d9fe6b791aeb P a1dff8a625984f11bc6111abf7ac5385: Deleting log segment in path: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618875398-13552-0/minicluster-data/ts-0-root/wals/2e47d2951d0646958a35d9fe6b791aeb/wal-000000014 (ops 65-69)
I20260812 06:20:21.070582 13670 maintenance_manager.cc:643] P a1dff8a625984f11bc6111abf7ac5385: LogGCOp(2e47d2951d0646958a35d9fe6b791aeb) complete. Timing: real 0.031s	user 0.006s	sys 0.023s Metrics: {}
I20260812 06:20:21.071123 13735 maintenance_manager.cc:419] P a1dff8a625984f11bc6111abf7ac5385: Scheduling UndoDeltaBlockGCOp(2e47d2951d0646958a35d9fe6b791aeb): 492 bytes on disk
I20260812 06:20:21.071696 13670 maintenance_manager.cc:643] P a1dff8a625984f11bc6111abf7ac5385: UndoDeltaBlockGCOp(2e47d2951d0646958a35d9fe6b791aeb) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4}
I20260812 06:20:21.072340 13735 maintenance_manager.cc:419] P a1dff8a625984f11bc6111abf7ac5385: Scheduling FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb): perf score=3.181125
I20260812 06:20:21.094683 13670 maintenance_manager.cc:643] P a1dff8a625984f11bc6111abf7ac5385: FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb) complete. Timing: real 0.022s	user 0.012s	sys 0.004s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":7204,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:21.095257 13735 maintenance_manager.cc:419] P a1dff8a625984f11bc6111abf7ac5385: Scheduling FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb): perf score=2.188937
I20260812 06:20:21.106314 13670 maintenance_manager.cc:643] P a1dff8a625984f11bc6111abf7ac5385: FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4036,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:21.106945 13735 maintenance_manager.cc:419] P a1dff8a625984f11bc6111abf7ac5385: Scheduling MajorDeltaCompactionOp(2e47d2951d0646958a35d9fe6b791aeb): perf score=1.000000
I20260812 06:20:21.339920 13670 maintenance_manager.cc:643] P a1dff8a625984f11bc6111abf7ac5385: MajorDeltaCompactionOp(2e47d2951d0646958a35d9fe6b791aeb) complete. Timing: real 0.233s	user 0.180s	sys 0.052s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32938772,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":249,"lbm_read_time_us":14951,"lbm_reads_lt_1ms":774,"lbm_write_time_us":41099,"lbm_writes_lt_1ms":743,"mutex_wait_us":56,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":2048,"thread_start_us":84,"threads_started":1,"update_count":3500}
I20260812 06:20:21.341890 13735 maintenance_manager.cc:419] P a1dff8a625984f11bc6111abf7ac5385: Scheduling FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb): perf score=14.095187
I20260812 06:20:21.400251 13670 maintenance_manager.cc:643] P a1dff8a625984f11bc6111abf7ac5385: FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb) complete. Timing: real 0.058s	user 0.024s	sys 0.020s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":21176,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2000}
I20260812 06:20:21.400992 13735 maintenance_manager.cc:419] P a1dff8a625984f11bc6111abf7ac5385: Scheduling FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb): perf score=2.188937
I20260812 06:20:21.415005 13670 maintenance_manager.cc:643] P a1dff8a625984f11bc6111abf7ac5385: FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb) complete. Timing: real 0.014s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5121,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:21.415522 13735 maintenance_manager.cc:419] P a1dff8a625984f11bc6111abf7ac5385: Scheduling MajorDeltaCompactionOp(2e47d2951d0646958a35d9fe6b791aeb): perf score=1.000000
I20260812 06:20:21.597620 13670 maintenance_manager.cc:643] P a1dff8a625984f11bc6111abf7ac5385: MajorDeltaCompactionOp(2e47d2951d0646958a35d9fe6b791aeb) complete. Timing: real 0.182s	user 0.129s	sys 0.051s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733726,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":185,"lbm_read_time_us":13183,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32430,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2500}
I20260812 06:20:21.598213 13735 maintenance_manager.cc:419] P a1dff8a625984f11bc6111abf7ac5385: Scheduling FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb): perf score=11.118625
I20260812 06:20:21.640017 13670 maintenance_manager.cc:643] P a1dff8a625984f11bc6111abf7ac5385: FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb) complete. Timing: real 0.042s	user 0.031s	sys 0.007s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":13643,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:21.640880 13735 maintenance_manager.cc:419] P a1dff8a625984f11bc6111abf7ac5385: Scheduling FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb): perf score=2.188937
I20260812 06:20:21.656698 13670 maintenance_manager.cc:643] P a1dff8a625984f11bc6111abf7ac5385: FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb) complete. Timing: real 0.016s	user 0.015s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5217,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:21.657409 13735 maintenance_manager.cc:419] P a1dff8a625984f11bc6111abf7ac5385: Scheduling MajorDeltaCompactionOp(2e47d2951d0646958a35d9fe6b791aeb): perf score=1.000000
I20260812 06:20:21.820962 13670 maintenance_manager.cc:643] P a1dff8a625984f11bc6111abf7ac5385: MajorDeltaCompactionOp(2e47d2951d0646958a35d9fe6b791aeb) complete. Timing: real 0.163s	user 0.118s	sys 0.045s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631303,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":707,"lbm_read_time_us":11130,"lbm_reads_lt_1ms":468,"lbm_write_time_us":26829,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":2000}
I20260812 06:20:21.821714 13735 maintenance_manager.cc:419] P a1dff8a625984f11bc6111abf7ac5385: Scheduling FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb): perf score=10.126437
I20260812 06:20:21.853945 13670 maintenance_manager.cc:643] P a1dff8a625984f11bc6111abf7ac5385: FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb) complete. Timing: real 0.032s	user 0.030s	sys 0.000s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14174,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:21.854592 13735 maintenance_manager.cc:419] P a1dff8a625984f11bc6111abf7ac5385: Scheduling FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb): perf score=2.188937
I20260812 06:20:21.871102 13670 maintenance_manager.cc:643] P a1dff8a625984f11bc6111abf7ac5385: FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb) complete. Timing: real 0.016s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6189,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:21.871778 13735 maintenance_manager.cc:419] P a1dff8a625984f11bc6111abf7ac5385: Scheduling MajorDeltaCompactionOp(2e47d2951d0646958a35d9fe6b791aeb): perf score=1.000000
I20260812 06:20:22.000675 13670 maintenance_manager.cc:643] P a1dff8a625984f11bc6111abf7ac5385: MajorDeltaCompactionOp(2e47d2951d0646958a35d9fe6b791aeb) complete. Timing: real 0.129s	user 0.108s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631311,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":722,"lbm_read_time_us":10233,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23131,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2000}
I20260812 06:20:22.001259 13735 maintenance_manager.cc:419] P a1dff8a625984f11bc6111abf7ac5385: Scheduling FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb): perf score=10.126437
I20260812 06:20:22.038280 13670 maintenance_manager.cc:643] P a1dff8a625984f11bc6111abf7ac5385: FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb) complete. Timing: real 0.037s	user 0.019s	sys 0.016s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":16033,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:22.038897 13735 maintenance_manager.cc:419] P a1dff8a625984f11bc6111abf7ac5385: Scheduling FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb): perf score=2.188937
I20260812 06:20:22.054658 13670 maintenance_manager.cc:643] P a1dff8a625984f11bc6111abf7ac5385: FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb) complete. Timing: real 0.016s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5846,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.055281 13735 maintenance_manager.cc:419] P a1dff8a625984f11bc6111abf7ac5385: Scheduling MajorDeltaCompactionOp(2e47d2951d0646958a35d9fe6b791aeb): perf score=1.000000
I20260812 06:20:22.192179 13670 maintenance_manager.cc:643] P a1dff8a625984f11bc6111abf7ac5385: MajorDeltaCompactionOp(2e47d2951d0646958a35d9fe6b791aeb) complete. Timing: real 0.137s	user 0.108s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631313,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":264,"lbm_read_time_us":9691,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26806,"lbm_writes_lt_1ms":443,"mutex_wait_us":49,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":22656,"update_count":2000}
I20260812 06:20:22.193145 13735 maintenance_manager.cc:419] P a1dff8a625984f11bc6111abf7ac5385: Scheduling FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb): perf score=10.126437
I20260812 06:20:22.240290 13670 maintenance_manager.cc:643] P a1dff8a625984f11bc6111abf7ac5385: FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb) complete. Timing: real 0.047s	user 0.031s	sys 0.011s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":18541,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:20:22.241117 13735 maintenance_manager.cc:419] P a1dff8a625984f11bc6111abf7ac5385: Scheduling FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb): perf score=2.188937
I20260812 06:20:22.253326 13670 maintenance_manager.cc:643] P a1dff8a625984f11bc6111abf7ac5385: FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4324,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.254069 13735 maintenance_manager.cc:419] P a1dff8a625984f11bc6111abf7ac5385: Scheduling MajorDeltaCompactionOp(2e47d2951d0646958a35d9fe6b791aeb): perf score=1.000000
I20260812 06:20:22.400609 13670 maintenance_manager.cc:643] P a1dff8a625984f11bc6111abf7ac5385: MajorDeltaCompactionOp(2e47d2951d0646958a35d9fe6b791aeb) complete. Timing: real 0.146s	user 0.105s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631314,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":885,"lbm_read_time_us":11372,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24820,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8832,"update_count":2000}
I20260812 06:20:22.401196 13735 maintenance_manager.cc:419] P a1dff8a625984f11bc6111abf7ac5385: Scheduling FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb): perf score=10.126437
I20260812 06:20:22.444638 13670 maintenance_manager.cc:643] P a1dff8a625984f11bc6111abf7ac5385: FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb) complete. Timing: real 0.043s	user 0.027s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19404,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:22.445207 13735 maintenance_manager.cc:419] P a1dff8a625984f11bc6111abf7ac5385: Scheduling FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb): perf score=2.188937
I20260812 06:20:22.458770 13670 maintenance_manager.cc:643] P a1dff8a625984f11bc6111abf7ac5385: FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb) complete. Timing: real 0.013s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4761,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.459403 13735 maintenance_manager.cc:419] P a1dff8a625984f11bc6111abf7ac5385: Scheduling MajorDeltaCompactionOp(2e47d2951d0646958a35d9fe6b791aeb): perf score=1.000000
I20260812 06:20:22.596873 13670 maintenance_manager.cc:643] P a1dff8a625984f11bc6111abf7ac5385: MajorDeltaCompactionOp(2e47d2951d0646958a35d9fe6b791aeb) complete. Timing: real 0.137s	user 0.110s	sys 0.027s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":254,"lbm_read_time_us":10312,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26591,"lbm_writes_lt_1ms":443,"mutex_wait_us":87,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":26880,"update_count":2000}
I20260812 06:20:22.597678 13735 maintenance_manager.cc:419] P a1dff8a625984f11bc6111abf7ac5385: Scheduling FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb): perf score=10.126437
I20260812 06:20:22.637584 13670 maintenance_manager.cc:643] P a1dff8a625984f11bc6111abf7ac5385: FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb) complete. Timing: real 0.040s	user 0.028s	sys 0.004s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":14913,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:22.638249 13735 maintenance_manager.cc:419] P a1dff8a625984f11bc6111abf7ac5385: Scheduling FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb): perf score=2.188937
I20260812 06:20:22.649950 13670 maintenance_manager.cc:643] P a1dff8a625984f11bc6111abf7ac5385: FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4313,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.650667 13735 maintenance_manager.cc:419] P a1dff8a625984f11bc6111abf7ac5385: Scheduling FlushMRSOp(2e47d2951d0646958a35d9fe6b791aeb): perf score=1.000000
I20260812 06:20:22.678447 13670 maintenance_manager.cc:643] P a1dff8a625984f11bc6111abf7ac5385: FlushMRSOp(2e47d2951d0646958a35d9fe6b791aeb) complete. Timing: real 0.028s	user 0.019s	sys 0.007s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":70,"dirs.run_cpu_time_us":254,"dirs.run_wall_time_us":1332,"drs_written":1,"lbm_read_time_us":57,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1728,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:20:22.679360 13735 maintenance_manager.cc:419] P a1dff8a625984f11bc6111abf7ac5385: Scheduling LogGCOp(2e47d2951d0646958a35d9fe6b791aeb): free 132571329 bytes of WAL
I20260812 06:20:22.679697 13670 log_reader.cc:385] T 2e47d2951d0646958a35d9fe6b791aeb: removed 13 log segments from log reader
I20260812 06:20:22.679772 13670 log.cc:1079] T 2e47d2951d0646958a35d9fe6b791aeb P a1dff8a625984f11bc6111abf7ac5385: Deleting log segment in path: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618875398-13552-0/minicluster-data/ts-0-root/wals/2e47d2951d0646958a35d9fe6b791aeb/wal-000000015 (ops 70-74)
I20260812 06:20:22.679863 13670 log.cc:1079] T 2e47d2951d0646958a35d9fe6b791aeb P a1dff8a625984f11bc6111abf7ac5385: Deleting log segment in path: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618875398-13552-0/minicluster-data/ts-0-root/wals/2e47d2951d0646958a35d9fe6b791aeb/wal-000000016 (ops 75-78)
I20260812 06:20:22.679924 13670 log.cc:1079] T 2e47d2951d0646958a35d9fe6b791aeb P a1dff8a625984f11bc6111abf7ac5385: Deleting log segment in path: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618875398-13552-0/minicluster-data/ts-0-root/wals/2e47d2951d0646958a35d9fe6b791aeb/wal-000000017 (ops 79-83)
I20260812 06:20:22.679965 13670 log.cc:1079] T 2e47d2951d0646958a35d9fe6b791aeb P a1dff8a625984f11bc6111abf7ac5385: Deleting log segment in path: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618875398-13552-0/minicluster-data/ts-0-root/wals/2e47d2951d0646958a35d9fe6b791aeb/wal-000000018 (ops 84-88)
I20260812 06:20:22.680001 13670 log.cc:1079] T 2e47d2951d0646958a35d9fe6b791aeb P a1dff8a625984f11bc6111abf7ac5385: Deleting log segment in path: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618875398-13552-0/minicluster-data/ts-0-root/wals/2e47d2951d0646958a35d9fe6b791aeb/wal-000000019 (ops 89-93)
I20260812 06:20:22.680043 13670 log.cc:1079] T 2e47d2951d0646958a35d9fe6b791aeb P a1dff8a625984f11bc6111abf7ac5385: Deleting log segment in path: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618875398-13552-0/minicluster-data/ts-0-root/wals/2e47d2951d0646958a35d9fe6b791aeb/wal-000000020 (ops 94-98)
I20260812 06:20:22.680080 13670 log.cc:1079] T 2e47d2951d0646958a35d9fe6b791aeb P a1dff8a625984f11bc6111abf7ac5385: Deleting log segment in path: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618875398-13552-0/minicluster-data/ts-0-root/wals/2e47d2951d0646958a35d9fe6b791aeb/wal-000000021 (ops 99-103)
I20260812 06:20:22.680116 13670 log.cc:1079] T 2e47d2951d0646958a35d9fe6b791aeb P a1dff8a625984f11bc6111abf7ac5385: Deleting log segment in path: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618875398-13552-0/minicluster-data/ts-0-root/wals/2e47d2951d0646958a35d9fe6b791aeb/wal-000000022 (ops 104-108)
I20260812 06:20:22.680153 13670 log.cc:1079] T 2e47d2951d0646958a35d9fe6b791aeb P a1dff8a625984f11bc6111abf7ac5385: Deleting log segment in path: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618875398-13552-0/minicluster-data/ts-0-root/wals/2e47d2951d0646958a35d9fe6b791aeb/wal-000000023 (ops 109-113)
I20260812 06:20:22.680192 13670 log.cc:1079] T 2e47d2951d0646958a35d9fe6b791aeb P a1dff8a625984f11bc6111abf7ac5385: Deleting log segment in path: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618875398-13552-0/minicluster-data/ts-0-root/wals/2e47d2951d0646958a35d9fe6b791aeb/wal-000000024 (ops 114-118)
I20260812 06:20:22.680227 13670 log.cc:1079] T 2e47d2951d0646958a35d9fe6b791aeb P a1dff8a625984f11bc6111abf7ac5385: Deleting log segment in path: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618875398-13552-0/minicluster-data/ts-0-root/wals/2e47d2951d0646958a35d9fe6b791aeb/wal-000000025 (ops 119-122)
I20260812 06:20:22.680264 13670 log.cc:1079] T 2e47d2951d0646958a35d9fe6b791aeb P a1dff8a625984f11bc6111abf7ac5385: Deleting log segment in path: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618875398-13552-0/minicluster-data/ts-0-root/wals/2e47d2951d0646958a35d9fe6b791aeb/wal-000000026 (ops 123-127)
I20260812 06:20:22.680299 13670 log.cc:1079] T 2e47d2951d0646958a35d9fe6b791aeb P a1dff8a625984f11bc6111abf7ac5385: Deleting log segment in path: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618875398-13552-0/minicluster-data/ts-0-root/wals/2e47d2951d0646958a35d9fe6b791aeb/wal-000000027 (ops 128-132)
I20260812 06:20:22.710312 13670 maintenance_manager.cc:643] P a1dff8a625984f11bc6111abf7ac5385: LogGCOp(2e47d2951d0646958a35d9fe6b791aeb) complete. Timing: real 0.031s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:20:22.710916 13735 maintenance_manager.cc:419] P a1dff8a625984f11bc6111abf7ac5385: Scheduling UndoDeltaBlockGCOp(2e47d2951d0646958a35d9fe6b791aeb): 483 bytes on disk
I20260812 06:20:22.711432 13670 maintenance_manager.cc:643] P a1dff8a625984f11bc6111abf7ac5385: UndoDeltaBlockGCOp(2e47d2951d0646958a35d9fe6b791aeb) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":60,"lbm_reads_lt_1ms":4}
I20260812 06:20:22.712042 13735 maintenance_manager.cc:419] P a1dff8a625984f11bc6111abf7ac5385: Scheduling FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb): perf score=4.173312
I20260812 06:20:22.728971 13670 maintenance_manager.cc:643] P a1dff8a625984f11bc6111abf7ac5385: FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb) complete. Timing: real 0.017s	user 0.016s	sys 0.000s Metrics: {"bytes_written":6112849,"delete_count":0,"lbm_write_time_us":6812,"lbm_writes_lt_1ms":152,"reinsert_count":0,"update_count":745}
I20260812 06:20:22.729522 13735 maintenance_manager.cc:419] P a1dff8a625984f11bc6111abf7ac5385: Scheduling FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb): perf score=1.000000
I20260812 06:20:22.739974 13670 maintenance_manager.cc:643] P a1dff8a625984f11bc6111abf7ac5385: FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":2092427,"delete_count":0,"lbm_write_time_us":3446,"lbm_writes_lt_1ms":54,"reinsert_count":0,"update_count":255}
I20260812 06:20:22.740689 13735 maintenance_manager.cc:419] P a1dff8a625984f11bc6111abf7ac5385: Scheduling MajorDeltaCompactionOp(2e47d2951d0646958a35d9fe6b791aeb): perf score=1.000000
I20260812 06:20:22.914193 13670 maintenance_manager.cc:643] P a1dff8a625984f11bc6111abf7ac5385: MajorDeltaCompactionOp(2e47d2951d0646958a35d9fe6b791aeb) complete. Timing: real 0.173s	user 0.138s	sys 0.035s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836329,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":594,"lbm_read_time_us":11262,"lbm_reads_lt_1ms":666,"lbm_write_time_us":36316,"lbm_writes_lt_1ms":643,"mutex_wait_us":23,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":7936,"thread_start_us":109,"threads_started":1,"update_count":3000}
I20260812 06:20:22.914891 13735 maintenance_manager.cc:419] P a1dff8a625984f11bc6111abf7ac5385: Scheduling FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb): perf score=14.095187
I20260812 06:20:22.973436 13670 maintenance_manager.cc:643] P a1dff8a625984f11bc6111abf7ac5385: FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb) complete. Timing: real 0.058s	user 0.021s	sys 0.036s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":28206,"lbm_writes_1-10_ms":4,"lbm_writes_lt_1ms":399,"reinsert_count":0,"update_count":2000}
I20260812 06:20:22.974064 13735 maintenance_manager.cc:419] P a1dff8a625984f11bc6111abf7ac5385: Scheduling FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb): perf score=2.188937
I20260812 06:20:22.989439 13670 maintenance_manager.cc:643] P a1dff8a625984f11bc6111abf7ac5385: FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb) complete. Timing: real 0.015s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5470,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.990181 13735 maintenance_manager.cc:419] P a1dff8a625984f11bc6111abf7ac5385: Scheduling MajorDeltaCompactionOp(2e47d2951d0646958a35d9fe6b791aeb): perf score=1.000000
I20260812 06:20:23.152849 13670 maintenance_manager.cc:643] P a1dff8a625984f11bc6111abf7ac5385: MajorDeltaCompactionOp(2e47d2951d0646958a35d9fe6b791aeb) complete. Timing: real 0.162s	user 0.125s	sys 0.032s 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":1264,"lbm_read_time_us":12014,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32416,"lbm_writes_lt_1ms":543,"mutex_wait_us":39,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":15104,"update_count":2500}
I20260812 06:20:23.153589 13735 maintenance_manager.cc:419] P a1dff8a625984f11bc6111abf7ac5385: Scheduling FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb): perf score=11.118625
I20260812 06:20:23.194975 13670 maintenance_manager.cc:643] P a1dff8a625984f11bc6111abf7ac5385: FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb) complete. Timing: real 0.041s	user 0.014s	sys 0.024s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":17012,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:23.195690 13735 maintenance_manager.cc:419] P a1dff8a625984f11bc6111abf7ac5385: Scheduling FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb): perf score=2.188937
I20260812 06:20:23.220299 13670 maintenance_manager.cc:643] P a1dff8a625984f11bc6111abf7ac5385: FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb) complete. Timing: real 0.024s	user 0.000s	sys 0.011s Metrics: {"bytes_written":3856509,"delete_count":0,"lbm_write_time_us":5057,"lbm_writes_lt_1ms":97,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":470}
I20260812 06:20:23.220820 13735 maintenance_manager.cc:419] P a1dff8a625984f11bc6111abf7ac5385: Scheduling FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb): perf score=2.188937
I20260812 06:20:23.231477 13670 maintenance_manager.cc:643] P a1dff8a625984f11bc6111abf7ac5385: FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb) complete. Timing: real 0.010s	user 0.000s	sys 0.008s Metrics: {"bytes_written":3938559,"delete_count":0,"lbm_write_time_us":3990,"lbm_writes_lt_1ms":99,"reinsert_count":0,"update_count":480}
I20260812 06:20:23.232040 13735 maintenance_manager.cc:419] P a1dff8a625984f11bc6111abf7ac5385: Scheduling MajorDeltaCompactionOp(2e47d2951d0646958a35d9fe6b791aeb): perf score=1.000000
I20260812 06:20:23.408115 13670 maintenance_manager.cc:643] P a1dff8a625984f11bc6111abf7ac5385: MajorDeltaCompactionOp(2e47d2951d0646958a35d9fe6b791aeb) complete. Timing: real 0.176s	user 0.128s	sys 0.044s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24733838,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":344,"lbm_read_time_us":10056,"lbm_reads_lt_1ms":573,"lbm_write_time_us":33943,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:20:23.408845 13735 maintenance_manager.cc:419] P a1dff8a625984f11bc6111abf7ac5385: Scheduling FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb): perf score=12.110812
I20260812 06:20:23.480487 13670 maintenance_manager.cc:643] P a1dff8a625984f11bc6111abf7ac5385: FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb) complete. Timing: real 0.071s	user 0.029s	sys 0.020s Metrics: {"bytes_written":13579241,"delete_count":0,"lbm_write_time_us":21998,"lbm_writes_lt_1ms":334,"reinsert_count":0,"update_count":1655}
I20260812 06:20:23.481205 13735 maintenance_manager.cc:419] P a1dff8a625984f11bc6111abf7ac5385: Scheduling FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb): perf score=5.165500
I20260812 06:20:23.507109 13670 maintenance_manager.cc:643] P a1dff8a625984f11bc6111abf7ac5385: FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb) complete. Timing: real 0.026s	user 0.009s	sys 0.009s Metrics: {"bytes_written":6933334,"delete_count":0,"lbm_write_time_us":8509,"lbm_writes_lt_1ms":172,"reinsert_count":0,"update_count":845}
I20260812 06:20:23.507736 13735 maintenance_manager.cc:419] P a1dff8a625984f11bc6111abf7ac5385: Scheduling MajorDeltaCompactionOp(2e47d2951d0646958a35d9fe6b791aeb): perf score=1.000000
I20260812 06:20:23.674299 13670 maintenance_manager.cc:643] P a1dff8a625984f11bc6111abf7ac5385: MajorDeltaCompactionOp(2e47d2951d0646958a35d9fe6b791aeb) complete. Timing: real 0.166s	user 0.115s	sys 0.051s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733732,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":311,"lbm_read_time_us":11317,"lbm_reads_lt_1ms":564,"lbm_write_time_us":31038,"lbm_writes_lt_1ms":543,"mutex_wait_us":54,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":94464,"update_count":2500}
I20260812 06:20:23.675419 13735 maintenance_manager.cc:419] P a1dff8a625984f11bc6111abf7ac5385: Scheduling FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb): perf score=14.095187
I20260812 06:20:23.731921 13670 maintenance_manager.cc:643] P a1dff8a625984f11bc6111abf7ac5385: FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb) complete. Timing: real 0.056s	user 0.023s	sys 0.028s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":26365,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2000}
I20260812 06:20:23.732566 13735 maintenance_manager.cc:419] P a1dff8a625984f11bc6111abf7ac5385: Scheduling FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb): perf score=2.188937
I20260812 06:20:23.743492 13670 maintenance_manager.cc:643] P a1dff8a625984f11bc6111abf7ac5385: FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4085,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:23.744040 13735 maintenance_manager.cc:419] P a1dff8a625984f11bc6111abf7ac5385: Scheduling MajorDeltaCompactionOp(2e47d2951d0646958a35d9fe6b791aeb): perf score=1.000000
I20260812 06:20:23.933554 13670 maintenance_manager.cc:643] P a1dff8a625984f11bc6111abf7ac5385: MajorDeltaCompactionOp(2e47d2951d0646958a35d9fe6b791aeb) complete. Timing: real 0.189s	user 0.129s	sys 0.059s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733724,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1101,"lbm_read_time_us":13556,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32484,"lbm_writes_lt_1ms":543,"mutex_wait_us":378,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:20:23.934155 13735 maintenance_manager.cc:419] P a1dff8a625984f11bc6111abf7ac5385: Scheduling FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb): perf score=14.095187
I20260812 06:20:23.996688 13670 maintenance_manager.cc:643] P a1dff8a625984f11bc6111abf7ac5385: FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb) complete. Timing: real 0.062s	user 0.039s	sys 0.023s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23918,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:23.997300 13735 maintenance_manager.cc:419] P a1dff8a625984f11bc6111abf7ac5385: Scheduling FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb): perf score=2.188937
I20260812 06:20:24.018534 13670 maintenance_manager.cc:643] P a1dff8a625984f11bc6111abf7ac5385: FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb) complete. Timing: real 0.021s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5488,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:24.019377 13735 maintenance_manager.cc:419] P a1dff8a625984f11bc6111abf7ac5385: Scheduling MajorDeltaCompactionOp(2e47d2951d0646958a35d9fe6b791aeb): perf score=1.000000
I20260812 06:20:24.212879 13670 maintenance_manager.cc:643] P a1dff8a625984f11bc6111abf7ac5385: MajorDeltaCompactionOp(2e47d2951d0646958a35d9fe6b791aeb) complete. Timing: real 0.193s	user 0.137s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733724,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":337,"lbm_read_time_us":13185,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31990,"lbm_writes_lt_1ms":543,"mutex_wait_us":41,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13952,"update_count":2500}
I20260812 06:20:24.213543 13735 maintenance_manager.cc:419] P a1dff8a625984f11bc6111abf7ac5385: Scheduling FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb): perf score=14.095187
I20260812 06:20:24.278721 13670 maintenance_manager.cc:643] P a1dff8a625984f11bc6111abf7ac5385: FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb) complete. Timing: real 0.065s	user 0.025s	sys 0.032s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":24367,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:24.279351 13735 maintenance_manager.cc:419] P a1dff8a625984f11bc6111abf7ac5385: Scheduling FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb): perf score=2.188937
I20260812 06:20:24.291122 13670 maintenance_manager.cc:643] P a1dff8a625984f11bc6111abf7ac5385: FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4574,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:24.291733 13735 maintenance_manager.cc:419] P a1dff8a625984f11bc6111abf7ac5385: Scheduling FlushMRSOp(2e47d2951d0646958a35d9fe6b791aeb): perf score=1.000000
I20260812 06:20:24.342633 13670 maintenance_manager.cc:643] P a1dff8a625984f11bc6111abf7ac5385: FlushMRSOp(2e47d2951d0646958a35d9fe6b791aeb) complete. Timing: real 0.051s	user 0.043s	sys 0.000s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":113,"dirs.run_cpu_time_us":210,"dirs.run_wall_time_us":1893,"drs_written":1,"lbm_read_time_us":70,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2329,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:20:24.343448 13735 maintenance_manager.cc:419] P a1dff8a625984f11bc6111abf7ac5385: Scheduling LogGCOp(2e47d2951d0646958a35d9fe6b791aeb): free 133477726 bytes of WAL
I20260812 06:20:24.343719 13670 log_reader.cc:385] T 2e47d2951d0646958a35d9fe6b791aeb: removed 13 log segments from log reader
I20260812 06:20:24.343765 13670 log.cc:1079] T 2e47d2951d0646958a35d9fe6b791aeb P a1dff8a625984f11bc6111abf7ac5385: Deleting log segment in path: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618875398-13552-0/minicluster-data/ts-0-root/wals/2e47d2951d0646958a35d9fe6b791aeb/wal-000000028 (ops 133-137)
I20260812 06:20:24.343796 13670 log.cc:1079] T 2e47d2951d0646958a35d9fe6b791aeb P a1dff8a625984f11bc6111abf7ac5385: Deleting log segment in path: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618875398-13552-0/minicluster-data/ts-0-root/wals/2e47d2951d0646958a35d9fe6b791aeb/wal-000000029 (ops 138-142)
I20260812 06:20:24.343864 13670 log.cc:1079] T 2e47d2951d0646958a35d9fe6b791aeb P a1dff8a625984f11bc6111abf7ac5385: Deleting log segment in path: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618875398-13552-0/minicluster-data/ts-0-root/wals/2e47d2951d0646958a35d9fe6b791aeb/wal-000000030 (ops 143-147)
I20260812 06:20:24.343909 13670 log.cc:1079] T 2e47d2951d0646958a35d9fe6b791aeb P a1dff8a625984f11bc6111abf7ac5385: Deleting log segment in path: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618875398-13552-0/minicluster-data/ts-0-root/wals/2e47d2951d0646958a35d9fe6b791aeb/wal-000000031 (ops 148-152)
I20260812 06:20:24.343956 13670 log.cc:1079] T 2e47d2951d0646958a35d9fe6b791aeb P a1dff8a625984f11bc6111abf7ac5385: Deleting log segment in path: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618875398-13552-0/minicluster-data/ts-0-root/wals/2e47d2951d0646958a35d9fe6b791aeb/wal-000000032 (ops 153-157)
I20260812 06:20:24.343999 13670 log.cc:1079] T 2e47d2951d0646958a35d9fe6b791aeb P a1dff8a625984f11bc6111abf7ac5385: Deleting log segment in path: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618875398-13552-0/minicluster-data/ts-0-root/wals/2e47d2951d0646958a35d9fe6b791aeb/wal-000000033 (ops 158-162)
I20260812 06:20:24.344044 13670 log.cc:1079] T 2e47d2951d0646958a35d9fe6b791aeb P a1dff8a625984f11bc6111abf7ac5385: Deleting log segment in path: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618875398-13552-0/minicluster-data/ts-0-root/wals/2e47d2951d0646958a35d9fe6b791aeb/wal-000000034 (ops 163-167)
I20260812 06:20:24.344110 13670 log.cc:1079] T 2e47d2951d0646958a35d9fe6b791aeb P a1dff8a625984f11bc6111abf7ac5385: Deleting log segment in path: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618875398-13552-0/minicluster-data/ts-0-root/wals/2e47d2951d0646958a35d9fe6b791aeb/wal-000000035 (ops 168-172)
I20260812 06:20:24.344151 13670 log.cc:1079] T 2e47d2951d0646958a35d9fe6b791aeb P a1dff8a625984f11bc6111abf7ac5385: Deleting log segment in path: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618875398-13552-0/minicluster-data/ts-0-root/wals/2e47d2951d0646958a35d9fe6b791aeb/wal-000000036 (ops 173-177)
I20260812 06:20:24.344192 13670 log.cc:1079] T 2e47d2951d0646958a35d9fe6b791aeb P a1dff8a625984f11bc6111abf7ac5385: Deleting log segment in path: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618875398-13552-0/minicluster-data/ts-0-root/wals/2e47d2951d0646958a35d9fe6b791aeb/wal-000000037 (ops 178-182)
I20260812 06:20:24.344235 13670 log.cc:1079] T 2e47d2951d0646958a35d9fe6b791aeb P a1dff8a625984f11bc6111abf7ac5385: Deleting log segment in path: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618875398-13552-0/minicluster-data/ts-0-root/wals/2e47d2951d0646958a35d9fe6b791aeb/wal-000000038 (ops 183-187)
I20260812 06:20:24.344277 13670 log.cc:1079] T 2e47d2951d0646958a35d9fe6b791aeb P a1dff8a625984f11bc6111abf7ac5385: Deleting log segment in path: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618875398-13552-0/minicluster-data/ts-0-root/wals/2e47d2951d0646958a35d9fe6b791aeb/wal-000000039 (ops 188-192)
I20260812 06:20:24.344316 13670 log.cc:1079] T 2e47d2951d0646958a35d9fe6b791aeb P a1dff8a625984f11bc6111abf7ac5385: Deleting log segment in path: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618875398-13552-0/minicluster-data/ts-0-root/wals/2e47d2951d0646958a35d9fe6b791aeb/wal-000000040 (ops 193-197)
I20260812 06:20:24.375514 13670 maintenance_manager.cc:643] P a1dff8a625984f11bc6111abf7ac5385: LogGCOp(2e47d2951d0646958a35d9fe6b791aeb) complete. Timing: real 0.032s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:20:24.376031 13735 maintenance_manager.cc:419] P a1dff8a625984f11bc6111abf7ac5385: Scheduling FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb): perf score=2.188937
I20260812 06:20:24.398715 13552 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.166s	user 1.901s	sys 0.154s
I20260812 06:20:24.400279 13670 maintenance_manager.cc:643] P a1dff8a625984f11bc6111abf7ac5385: FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb) complete. Timing: real 0.024s	user 0.011s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6514,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:24.400957 13735 maintenance_manager.cc:419] P a1dff8a625984f11bc6111abf7ac5385: Scheduling UndoDeltaBlockGCOp(2e47d2951d0646958a35d9fe6b791aeb): 492 bytes on disk
I20260812 06:20:24.401535 13670 maintenance_manager.cc:643] P a1dff8a625984f11bc6111abf7ac5385: UndoDeltaBlockGCOp(2e47d2951d0646958a35d9fe6b791aeb) 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:24.402222 13735 maintenance_manager.cc:419] P a1dff8a625984f11bc6111abf7ac5385: Scheduling FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb): perf score=2.188937
I20260812 06:20:24.418439 13670 maintenance_manager.cc:643] P a1dff8a625984f11bc6111abf7ac5385: FlushDeltaMemStoresOp(2e47d2951d0646958a35d9fe6b791aeb) complete. Timing: real 0.016s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6641,"lbm_writes_lt_1ms":103,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":500}
I20260812 06:20:24.419168 13735 maintenance_manager.cc:419] P a1dff8a625984f11bc6111abf7ac5385: Scheduling MajorDeltaCompactionOp(2e47d2951d0646958a35d9fe6b791aeb): perf score=1.000000
I20260812 06:20:24.503257 13552 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.104s	user 0.002s	sys 0.000s
I20260812 06:20:24.503983 13552 tablet_server.cc:179] TabletServer@127.13.60.1:0 shutting down...
I20260812 06:20:24.607240 13670 maintenance_manager.cc:643] P a1dff8a625984f11bc6111abf7ac5385: MajorDeltaCompactionOp(2e47d2951d0646958a35d9fe6b791aeb) complete. Timing: real 0.188s	user 0.113s	sys 0.074s Metrics: {"cfile_cache_hit":204,"cfile_cache_hit_bytes":8251441,"cfile_cache_miss":530,"cfile_cache_miss_bytes":24687344,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":514,"lbm_read_time_us":11046,"lbm_reads_lt_1ms":562,"lbm_write_time_us":37754,"lbm_writes_lt_1ms":743,"mutex_wait_us":86,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":22400,"thread_start_us":81,"threads_started":1,"update_count":3500}
I20260812 06:20:24.608913 13552 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:24.609362 13552 tablet_replica.cc:333] T 2e47d2951d0646958a35d9fe6b791aeb P a1dff8a625984f11bc6111abf7ac5385: stopping tablet replica
I20260812 06:20:24.609650 13552 raft_consensus.cc:2243] T 2e47d2951d0646958a35d9fe6b791aeb P a1dff8a625984f11bc6111abf7ac5385 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:24.609918 13552 raft_consensus.cc:2272] T 2e47d2951d0646958a35d9fe6b791aeb P a1dff8a625984f11bc6111abf7ac5385 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:24.626700 13552 tablet_server.cc:196] TabletServer@127.13.60.1:0 shutdown complete.
I20260812 06:20:24.667933 13552 master.cc:562] Master@127.13.60.62:39259 shutting down...
I20260812 06:20:24.672583 13552 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 0e98853c48bf48d6b2b488c531018c90 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:24.672827 13552 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 0e98853c48bf48d6b2b488c531018c90 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:24.672935 13552 tablet_replica.cc:333] T 00000000000000000000000000000000 P 0e98853c48bf48d6b2b488c531018c90: stopping tablet replica
I20260812 06:20:24.685993 13552 master.cc:584] Master@127.13.60.62:39259 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5892 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:20:24.790529 13552 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.13.60.62:40879
I20260812 06:20:24.791023 13552 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:24.793265 13778 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:24.793365 13780 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:24.793331 13552 server_base.cc:1061] running on GCE node
W20260812 06:20:24.793466 13777 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:24.793795 13552 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:24.793840 13552 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:24.793856 13552 hybrid_clock.cc:648] HybridClock initialized: now 1786515624793856 us; error 0 us; skew 500 ppm
I20260812 06:20:24.794692 13552 webserver.cc:533] Webserver started at http://127.13.60.62:39371/ using document root <none> and password file <none>
I20260812 06:20:24.794880 13552 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:24.794931 13552 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:24.794988 13552 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:24.795368 13552 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618875398-13552-0/minicluster-data/master-0-root/instance:
uuid: "04298685eaa44694925f6f635df5ee58"
format_stamp: "Formatted at 2026-08-12 06:20:24 on dist-test-slave-fd7l"
I20260812 06:20:24.796947 13552 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:20:24.797927 13786 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:24.798316 13552 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:20:24.798465 13552 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618875398-13552-0/minicluster-data/master-0-root
uuid: "04298685eaa44694925f6f635df5ee58"
format_stamp: "Formatted at 2026-08-12 06:20:24 on dist-test-slave-fd7l"
I20260812 06:20:24.798600 13552 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618875398-13552-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618875398-13552-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618875398-13552-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:24.829172 13552 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:24.829674 13552 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:24.834424 13552 rpc_server.cc:307] RPC server started. Bound to: 127.13.60.62:40879
I20260812 06:20:24.835887 13847 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.13.60.62:40879 every 8 connection(s)
I20260812 06:20:24.841585 13848 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:24.845561 13848 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 04298685eaa44694925f6f635df5ee58: Bootstrap starting.
I20260812 06:20:24.846393 13848 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 04298685eaa44694925f6f635df5ee58: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:24.847456 13848 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 04298685eaa44694925f6f635df5ee58: No bootstrap required, opened a new log
I20260812 06:20:24.847819 13848 raft_consensus.cc:359] T 00000000000000000000000000000000 P 04298685eaa44694925f6f635df5ee58 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "04298685eaa44694925f6f635df5ee58" member_type: VOTER }
I20260812 06:20:24.847903 13848 raft_consensus.cc:385] T 00000000000000000000000000000000 P 04298685eaa44694925f6f635df5ee58 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:24.847925 13848 raft_consensus.cc:740] T 00000000000000000000000000000000 P 04298685eaa44694925f6f635df5ee58 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 04298685eaa44694925f6f635df5ee58, State: Initialized, Role: FOLLOWER
I20260812 06:20:24.848030 13848 consensus_queue.cc:260] T 00000000000000000000000000000000 P 04298685eaa44694925f6f635df5ee58 [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: "04298685eaa44694925f6f635df5ee58" member_type: VOTER }
I20260812 06:20:24.848101 13848 raft_consensus.cc:399] T 00000000000000000000000000000000 P 04298685eaa44694925f6f635df5ee58 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:24.848124 13848 raft_consensus.cc:493] T 00000000000000000000000000000000 P 04298685eaa44694925f6f635df5ee58 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:24.848206 13848 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 04298685eaa44694925f6f635df5ee58 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:24.848943 13848 raft_consensus.cc:515] T 00000000000000000000000000000000 P 04298685eaa44694925f6f635df5ee58 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "04298685eaa44694925f6f635df5ee58" member_type: VOTER }
I20260812 06:20:24.849115 13848 leader_election.cc:304] T 00000000000000000000000000000000 P 04298685eaa44694925f6f635df5ee58 [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: 04298685eaa44694925f6f635df5ee58; no voters: 
I20260812 06:20:24.849354 13848 leader_election.cc:290] T 00000000000000000000000000000000 P 04298685eaa44694925f6f635df5ee58 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:24.849489 13851 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 04298685eaa44694925f6f635df5ee58 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:24.849838 13851 raft_consensus.cc:697] T 00000000000000000000000000000000 P 04298685eaa44694925f6f635df5ee58 [term 1 LEADER]: Becoming Leader. State: Replica: 04298685eaa44694925f6f635df5ee58, State: Running, Role: LEADER
I20260812 06:20:24.849839 13848 sys_catalog.cc:565] T 00000000000000000000000000000000 P 04298685eaa44694925f6f635df5ee58 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:24.850018 13851 consensus_queue.cc:237] T 00000000000000000000000000000000 P 04298685eaa44694925f6f635df5ee58 [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: "04298685eaa44694925f6f635df5ee58" member_type: VOTER }
I20260812 06:20:24.850461 13852 sys_catalog.cc:455] T 00000000000000000000000000000000 P 04298685eaa44694925f6f635df5ee58 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "04298685eaa44694925f6f635df5ee58" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "04298685eaa44694925f6f635df5ee58" member_type: VOTER } }
I20260812 06:20:24.850607 13852 sys_catalog.cc:458] T 00000000000000000000000000000000 P 04298685eaa44694925f6f635df5ee58 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:24.850478 13853 sys_catalog.cc:455] T 00000000000000000000000000000000 P 04298685eaa44694925f6f635df5ee58 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 04298685eaa44694925f6f635df5ee58. Latest consensus state: current_term: 1 leader_uuid: "04298685eaa44694925f6f635df5ee58" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "04298685eaa44694925f6f635df5ee58" member_type: VOTER } }
I20260812 06:20:24.850879 13853 sys_catalog.cc:458] T 00000000000000000000000000000000 P 04298685eaa44694925f6f635df5ee58 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:24.850890 13858 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:24.851738 13858 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:24.851895 13552 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:24.853698 13858 catalog_manager.cc:1383] Generated new cluster ID: face188084254cb8a02ccc024a013792
I20260812 06:20:24.853760 13858 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:24.873548 13858 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:24.874325 13858 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:24.881590 13858 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 04298685eaa44694925f6f635df5ee58: Generated new TSK 0
I20260812 06:20:24.881902 13858 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:24.884375 13552 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:24.886950 13874 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:24.887087 13552 server_base.cc:1061] running on GCE node
W20260812 06:20:24.886960 13870 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:24.887287 13871 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:24.887590 13552 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:24.887637 13552 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:24.887655 13552 hybrid_clock.cc:648] HybridClock initialized: now 1786515624887654 us; error 0 us; skew 500 ppm
I20260812 06:20:24.888720 13552 webserver.cc:533] Webserver started at http://127.13.60.1:41457/ using document root <none> and password file <none>
I20260812 06:20:24.888882 13552 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:24.888934 13552 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:24.888995 13552 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:24.889423 13552 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618875398-13552-0/minicluster-data/ts-0-root/instance:
uuid: "bfe5919082ef460a978e3aebd8bd6f76"
format_stamp: "Formatted at 2026-08-12 06:20:24 on dist-test-slave-fd7l"
I20260812 06:20:24.891225 13552 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:20:24.892409 13879 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:24.892814 13552 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:20:24.892922 13552 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618875398-13552-0/minicluster-data/ts-0-root
uuid: "bfe5919082ef460a978e3aebd8bd6f76"
format_stamp: "Formatted at 2026-08-12 06:20:24 on dist-test-slave-fd7l"
I20260812 06:20:24.893033 13552 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618875398-13552-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618875398-13552-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618875398-13552-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:24.910142 13552 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:24.910735 13552 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:24.911108 13552 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:24.911634 13552 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:24.911698 13552 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:24.911760 13552 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:24.911811 13552 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:24.916764 13552 rpc_server.cc:307] RPC server started. Bound to: 127.13.60.1:34579
I20260812 06:20:24.916857 13956 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.13.60.1:34579 every 8 connection(s)
I20260812 06:20:24.927045 13957 heartbeater.cc:344] Connected to a master server at 127.13.60.62:40879
I20260812 06:20:24.927208 13957 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:24.927536 13957 heartbeater.cc:507] Master 127.13.60.62:40879 requested a full tablet report, sending...
I20260812 06:20:24.928493 13802 ts_manager.cc:194] Registered new tserver with Master: bfe5919082ef460a978e3aebd8bd6f76 (127.13.60.1:34579)
I20260812 06:20:24.928603 13552 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.011467298s
I20260812 06:20:24.929514 13802 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:39602
I20260812 06:20:24.937580 13802 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:39604:
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:24.947713 13911 tablet_service.cc:1511] Processing CreateTablet for tablet 984a27d312f04e1d97a10e5e26552d1a (DEFAULT_TABLE table=heavy-update-compaction-test [id=48a0fae31e2345d2bbc9a19932b78baf]), partition=
I20260812 06:20:24.948057 13911 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 984a27d312f04e1d97a10e5e26552d1a. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:24.950418 13969 tablet_bootstrap.cc:492] T 984a27d312f04e1d97a10e5e26552d1a P bfe5919082ef460a978e3aebd8bd6f76: Bootstrap starting.
I20260812 06:20:24.951584 13969 tablet_bootstrap.cc:654] T 984a27d312f04e1d97a10e5e26552d1a P bfe5919082ef460a978e3aebd8bd6f76: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:24.953116 13969 tablet_bootstrap.cc:492] T 984a27d312f04e1d97a10e5e26552d1a P bfe5919082ef460a978e3aebd8bd6f76: No bootstrap required, opened a new log
I20260812 06:20:24.953227 13969 ts_tablet_manager.cc:1403] T 984a27d312f04e1d97a10e5e26552d1a P bfe5919082ef460a978e3aebd8bd6f76: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:20:24.953814 13969 raft_consensus.cc:359] T 984a27d312f04e1d97a10e5e26552d1a P bfe5919082ef460a978e3aebd8bd6f76 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "bfe5919082ef460a978e3aebd8bd6f76" member_type: VOTER last_known_addr { host: "127.13.60.1" port: 34579 } }
I20260812 06:20:24.953917 13969 raft_consensus.cc:385] T 984a27d312f04e1d97a10e5e26552d1a P bfe5919082ef460a978e3aebd8bd6f76 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:24.953943 13969 raft_consensus.cc:740] T 984a27d312f04e1d97a10e5e26552d1a P bfe5919082ef460a978e3aebd8bd6f76 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: bfe5919082ef460a978e3aebd8bd6f76, State: Initialized, Role: FOLLOWER
I20260812 06:20:24.954133 13969 consensus_queue.cc:260] T 984a27d312f04e1d97a10e5e26552d1a P bfe5919082ef460a978e3aebd8bd6f76 [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: "bfe5919082ef460a978e3aebd8bd6f76" member_type: VOTER last_known_addr { host: "127.13.60.1" port: 34579 } }
I20260812 06:20:24.954213 13969 raft_consensus.cc:399] T 984a27d312f04e1d97a10e5e26552d1a P bfe5919082ef460a978e3aebd8bd6f76 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:24.954263 13969 raft_consensus.cc:493] T 984a27d312f04e1d97a10e5e26552d1a P bfe5919082ef460a978e3aebd8bd6f76 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:24.954326 13969 raft_consensus.cc:3060] T 984a27d312f04e1d97a10e5e26552d1a P bfe5919082ef460a978e3aebd8bd6f76 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:24.955173 13969 raft_consensus.cc:515] T 984a27d312f04e1d97a10e5e26552d1a P bfe5919082ef460a978e3aebd8bd6f76 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "bfe5919082ef460a978e3aebd8bd6f76" member_type: VOTER last_known_addr { host: "127.13.60.1" port: 34579 } }
I20260812 06:20:24.955336 13969 leader_election.cc:304] T 984a27d312f04e1d97a10e5e26552d1a P bfe5919082ef460a978e3aebd8bd6f76 [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: bfe5919082ef460a978e3aebd8bd6f76; no voters: 
I20260812 06:20:24.955612 13969 leader_election.cc:290] T 984a27d312f04e1d97a10e5e26552d1a P bfe5919082ef460a978e3aebd8bd6f76 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:24.955772 13972 raft_consensus.cc:2804] T 984a27d312f04e1d97a10e5e26552d1a P bfe5919082ef460a978e3aebd8bd6f76 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:24.956032 13969 ts_tablet_manager.cc:1434] T 984a27d312f04e1d97a10e5e26552d1a P bfe5919082ef460a978e3aebd8bd6f76: Time spent starting tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:20:24.956157 13957 heartbeater.cc:499] Master 127.13.60.62:40879 was elected leader, sending a full tablet report...
I20260812 06:20:24.956163 13972 raft_consensus.cc:697] T 984a27d312f04e1d97a10e5e26552d1a P bfe5919082ef460a978e3aebd8bd6f76 [term 1 LEADER]: Becoming Leader. State: Replica: bfe5919082ef460a978e3aebd8bd6f76, State: Running, Role: LEADER
I20260812 06:20:24.956380 13972 consensus_queue.cc:237] T 984a27d312f04e1d97a10e5e26552d1a P bfe5919082ef460a978e3aebd8bd6f76 [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: "bfe5919082ef460a978e3aebd8bd6f76" member_type: VOTER last_known_addr { host: "127.13.60.1" port: 34579 } }
I20260812 06:20:24.958058 13802 catalog_manager.cc:5719] T 984a27d312f04e1d97a10e5e26552d1a P bfe5919082ef460a978e3aebd8bd6f76 reported cstate change: term changed from 0 to 1, leader changed from <none> to bfe5919082ef460a978e3aebd8bd6f76 (127.13.60.1). New cstate: current_term: 1 leader_uuid: "bfe5919082ef460a978e3aebd8bd6f76" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "bfe5919082ef460a978e3aebd8bd6f76" member_type: VOTER last_known_addr { host: "127.13.60.1" port: 34579 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:25.024020 13552 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.060s	user 0.017s	sys 0.009s
I20260812 06:20:25.168495 13958 maintenance_manager.cc:419] P bfe5919082ef460a978e3aebd8bd6f76: Scheduling FlushMRSOp(984a27d312f04e1d97a10e5e26552d1a): perf score=18.062753
I20260812 06:20:25.317018 13884 maintenance_manager.cc:643] P bfe5919082ef460a978e3aebd8bd6f76: FlushMRSOp(984a27d312f04e1d97a10e5e26552d1a) complete. Timing: real 0.148s	user 0.092s	sys 0.056s Metrics: {"bytes_written":8451225,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":74,"dirs.run_cpu_time_us":164,"dirs.run_wall_time_us":1107,"drs_written":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4,"lbm_write_time_us":36708,"lbm_writes_lt_1ms":663,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1030}
I20260812 06:20:25.317919 13958 maintenance_manager.cc:419] P bfe5919082ef460a978e3aebd8bd6f76: Scheduling LogGCOp(984a27d312f04e1d97a10e5e26552d1a): free 20743880 bytes of WAL
I20260812 06:20:25.318190 13884 log_reader.cc:385] T 984a27d312f04e1d97a10e5e26552d1a: removed 2 log segments from log reader
I20260812 06:20:25.318238 13884 log.cc:1079] T 984a27d312f04e1d97a10e5e26552d1a P bfe5919082ef460a978e3aebd8bd6f76: Deleting log segment in path: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618875398-13552-0/minicluster-data/ts-0-root/wals/984a27d312f04e1d97a10e5e26552d1a/wal-000000001 (ops 1-6)
I20260812 06:20:25.318269 13884 log.cc:1079] T 984a27d312f04e1d97a10e5e26552d1a P bfe5919082ef460a978e3aebd8bd6f76: Deleting log segment in path: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618875398-13552-0/minicluster-data/ts-0-root/wals/984a27d312f04e1d97a10e5e26552d1a/wal-000000002 (ops 7-11)
I20260812 06:20:25.322757 13884 maintenance_manager.cc:643] P bfe5919082ef460a978e3aebd8bd6f76: LogGCOp(984a27d312f04e1d97a10e5e26552d1a) complete. Timing: real 0.005s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:20:25.323240 13958 maintenance_manager.cc:419] P bfe5919082ef460a978e3aebd8bd6f76: Scheduling UndoDeltaBlockGCOp(984a27d312f04e1d97a10e5e26552d1a): 16411391 bytes on disk
I20260812 06:20:25.323779 13884 maintenance_manager.cc:643] P bfe5919082ef460a978e3aebd8bd6f76: UndoDeltaBlockGCOp(984a27d312f04e1d97a10e5e26552d1a) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4}
I20260812 06:20:25.324254 13958 maintenance_manager.cc:419] P bfe5919082ef460a978e3aebd8bd6f76: Scheduling FlushDeltaMemStoresOp(984a27d312f04e1d97a10e5e26552d1a): perf score=2.188937
I20260812 06:20:25.340158 13884 maintenance_manager.cc:643] P bfe5919082ef460a978e3aebd8bd6f76: FlushDeltaMemStoresOp(984a27d312f04e1d97a10e5e26552d1a) complete. Timing: real 0.016s	user 0.003s	sys 0.011s Metrics: {"bytes_written":3856508,"delete_count":0,"lbm_write_time_us":6269,"lbm_writes_lt_1ms":97,"reinsert_count":0,"update_count":470}
I20260812 06:20:25.340745 13958 maintenance_manager.cc:419] P bfe5919082ef460a978e3aebd8bd6f76: Scheduling MajorDeltaCompactionOp(984a27d312f04e1d97a10e5e26552d1a): perf score=1.000000
I20260812 06:20:25.478614 13884 maintenance_manager.cc:643] P bfe5919082ef460a978e3aebd8bd6f76: MajorDeltaCompactionOp(984a27d312f04e1d97a10e5e26552d1a) complete. Timing: real 0.138s	user 0.097s	sys 0.037s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16569861,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":593,"lbm_read_time_us":8409,"lbm_reads_lt_1ms":364,"lbm_write_time_us":23093,"lbm_writes_lt_1ms":343,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":768,"thread_start_us":332,"threads_started":5,"update_count":1500}
I20260812 06:20:25.479390 13958 maintenance_manager.cc:419] P bfe5919082ef460a978e3aebd8bd6f76: Scheduling FlushDeltaMemStoresOp(984a27d312f04e1d97a10e5e26552d1a): perf score=10.126437
I20260812 06:20:25.524160 13884 maintenance_manager.cc:643] P bfe5919082ef460a978e3aebd8bd6f76: FlushDeltaMemStoresOp(984a27d312f04e1d97a10e5e26552d1a) complete. Timing: real 0.045s	user 0.025s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15748,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:25.524734 13958 maintenance_manager.cc:419] P bfe5919082ef460a978e3aebd8bd6f76: Scheduling FlushDeltaMemStoresOp(984a27d312f04e1d97a10e5e26552d1a): perf score=2.188937
I20260812 06:20:25.536397 13884 maintenance_manager.cc:643] P bfe5919082ef460a978e3aebd8bd6f76: FlushDeltaMemStoresOp(984a27d312f04e1d97a10e5e26552d1a) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4162,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:25.537194 13958 maintenance_manager.cc:419] P bfe5919082ef460a978e3aebd8bd6f76: Scheduling MajorDeltaCompactionOp(984a27d312f04e1d97a10e5e26552d1a): perf score=1.000000
I20260812 06:20:25.677526 13884 maintenance_manager.cc:643] P bfe5919082ef460a978e3aebd8bd6f76: MajorDeltaCompactionOp(984a27d312f04e1d97a10e5e26552d1a) complete. Timing: real 0.140s	user 0.093s	sys 0.046s 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":626,"lbm_read_time_us":10385,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26853,"lbm_writes_lt_1ms":443,"mutex_wait_us":58,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11264,"update_count":2000}
I20260812 06:20:25.678030 13958 maintenance_manager.cc:419] P bfe5919082ef460a978e3aebd8bd6f76: Scheduling FlushDeltaMemStoresOp(984a27d312f04e1d97a10e5e26552d1a): perf score=10.126437
I20260812 06:20:25.727249 13884 maintenance_manager.cc:643] P bfe5919082ef460a978e3aebd8bd6f76: FlushDeltaMemStoresOp(984a27d312f04e1d97a10e5e26552d1a) complete. Timing: real 0.049s	user 0.019s	sys 0.017s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":16957,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:20:25.727798 13958 maintenance_manager.cc:419] P bfe5919082ef460a978e3aebd8bd6f76: Scheduling FlushDeltaMemStoresOp(984a27d312f04e1d97a10e5e26552d1a): perf score=2.188937
I20260812 06:20:25.740751 13884 maintenance_manager.cc:643] P bfe5919082ef460a978e3aebd8bd6f76: FlushDeltaMemStoresOp(984a27d312f04e1d97a10e5e26552d1a) complete. Timing: real 0.013s	user 0.009s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4627,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:25.741279 13958 maintenance_manager.cc:419] P bfe5919082ef460a978e3aebd8bd6f76: Scheduling MajorDeltaCompactionOp(984a27d312f04e1d97a10e5e26552d1a): perf score=1.000000
I20260812 06:20:25.879864 13884 maintenance_manager.cc:643] P bfe5919082ef460a978e3aebd8bd6f76: MajorDeltaCompactionOp(984a27d312f04e1d97a10e5e26552d1a) complete. Timing: real 0.138s	user 0.100s	sys 0.037s 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":236,"lbm_read_time_us":11878,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25379,"lbm_writes_lt_1ms":443,"mutex_wait_us":73,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":26752,"update_count":2000}
I20260812 06:20:25.880743 13958 maintenance_manager.cc:419] P bfe5919082ef460a978e3aebd8bd6f76: Scheduling FlushDeltaMemStoresOp(984a27d312f04e1d97a10e5e26552d1a): perf score=10.126437
I20260812 06:20:25.928218 13884 maintenance_manager.cc:643] P bfe5919082ef460a978e3aebd8bd6f76: FlushDeltaMemStoresOp(984a27d312f04e1d97a10e5e26552d1a) complete. Timing: real 0.047s	user 0.030s	sys 0.009s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":18568,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:25.928773 13958 maintenance_manager.cc:419] P bfe5919082ef460a978e3aebd8bd6f76: Scheduling FlushDeltaMemStoresOp(984a27d312f04e1d97a10e5e26552d1a): perf score=2.188937
I20260812 06:20:25.940245 13884 maintenance_manager.cc:643] P bfe5919082ef460a978e3aebd8bd6f76: FlushDeltaMemStoresOp(984a27d312f04e1d97a10e5e26552d1a) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4287,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:25.941183 13958 maintenance_manager.cc:419] P bfe5919082ef460a978e3aebd8bd6f76: Scheduling MajorDeltaCompactionOp(984a27d312f04e1d97a10e5e26552d1a): perf score=1.000000
I20260812 06:20:26.072598 13884 maintenance_manager.cc:643] P bfe5919082ef460a978e3aebd8bd6f76: MajorDeltaCompactionOp(984a27d312f04e1d97a10e5e26552d1a) complete. Timing: real 0.131s	user 0.104s	sys 0.027s 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":535,"lbm_read_time_us":10338,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25099,"lbm_writes_lt_1ms":443,"mutex_wait_us":302,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":18432,"update_count":2000}
I20260812 06:20:26.073350 13958 maintenance_manager.cc:419] P bfe5919082ef460a978e3aebd8bd6f76: Scheduling FlushDeltaMemStoresOp(984a27d312f04e1d97a10e5e26552d1a): perf score=10.126437
I20260812 06:20:26.122174 13884 maintenance_manager.cc:643] P bfe5919082ef460a978e3aebd8bd6f76: FlushDeltaMemStoresOp(984a27d312f04e1d97a10e5e26552d1a) complete. Timing: real 0.049s	user 0.029s	sys 0.018s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":16857,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:26.122870 13958 maintenance_manager.cc:419] P bfe5919082ef460a978e3aebd8bd6f76: Scheduling FlushDeltaMemStoresOp(984a27d312f04e1d97a10e5e26552d1a): perf score=2.188937
I20260812 06:20:26.135435 13884 maintenance_manager.cc:643] P bfe5919082ef460a978e3aebd8bd6f76: FlushDeltaMemStoresOp(984a27d312f04e1d97a10e5e26552d1a) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4469,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:26.135964 13958 maintenance_manager.cc:419] P bfe5919082ef460a978e3aebd8bd6f76: Scheduling MajorDeltaCompactionOp(984a27d312f04e1d97a10e5e26552d1a): perf score=1.000000
I20260812 06:20:26.305898 13884 maintenance_manager.cc:643] P bfe5919082ef460a978e3aebd8bd6f76: MajorDeltaCompactionOp(984a27d312f04e1d97a10e5e26552d1a) complete. Timing: real 0.170s	user 0.102s	sys 0.068s 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":615,"lbm_read_time_us":15440,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27441,"lbm_writes_lt_1ms":443,"mutex_wait_us":42,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":17536,"update_count":2000}
I20260812 06:20:26.306403 13958 maintenance_manager.cc:419] P bfe5919082ef460a978e3aebd8bd6f76: Scheduling FlushDeltaMemStoresOp(984a27d312f04e1d97a10e5e26552d1a): perf score=10.126437
I20260812 06:20:26.343753 13884 maintenance_manager.cc:643] P bfe5919082ef460a978e3aebd8bd6f76: FlushDeltaMemStoresOp(984a27d312f04e1d97a10e5e26552d1a) complete. Timing: real 0.037s	user 0.017s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16654,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:26.344563 13958 maintenance_manager.cc:419] P bfe5919082ef460a978e3aebd8bd6f76: Scheduling FlushDeltaMemStoresOp(984a27d312f04e1d97a10e5e26552d1a): perf score=2.188937
I20260812 06:20:26.362844 13884 maintenance_manager.cc:643] P bfe5919082ef460a978e3aebd8bd6f76: FlushDeltaMemStoresOp(984a27d312f04e1d97a10e5e26552d1a) complete. Timing: real 0.018s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6052,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:26.363462 13958 maintenance_manager.cc:419] P bfe5919082ef460a978e3aebd8bd6f76: Scheduling MajorDeltaCompactionOp(984a27d312f04e1d97a10e5e26552d1a): perf score=1.000000
I20260812 06:20:26.497248 13884 maintenance_manager.cc:643] P bfe5919082ef460a978e3aebd8bd6f76: MajorDeltaCompactionOp(984a27d312f04e1d97a10e5e26552d1a) complete. Timing: real 0.134s	user 0.110s	sys 0.023s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":960,"lbm_read_time_us":10093,"lbm_reads_lt_1ms":464,"lbm_write_time_us":26468,"lbm_writes_lt_1ms":443,"mutex_wait_us":273,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":18816,"update_count":2000}
I20260812 06:20:26.497885 13958 maintenance_manager.cc:419] P bfe5919082ef460a978e3aebd8bd6f76: Scheduling FlushDeltaMemStoresOp(984a27d312f04e1d97a10e5e26552d1a): perf score=10.126437
I20260812 06:20:26.543480 13884 maintenance_manager.cc:643] P bfe5919082ef460a978e3aebd8bd6f76: FlushDeltaMemStoresOp(984a27d312f04e1d97a10e5e26552d1a) complete. Timing: real 0.045s	user 0.039s	sys 0.000s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18573,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:26.543983 13958 maintenance_manager.cc:419] P bfe5919082ef460a978e3aebd8bd6f76: Scheduling FlushDeltaMemStoresOp(984a27d312f04e1d97a10e5e26552d1a): perf score=2.188937
I20260812 06:20:26.556418 13884 maintenance_manager.cc:643] P bfe5919082ef460a978e3aebd8bd6f76: FlushDeltaMemStoresOp(984a27d312f04e1d97a10e5e26552d1a) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4376,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:26.557284 13958 maintenance_manager.cc:419] P bfe5919082ef460a978e3aebd8bd6f76: Scheduling MajorDeltaCompactionOp(984a27d312f04e1d97a10e5e26552d1a): perf score=1.000000
I20260812 06:20:26.707072 13884 maintenance_manager.cc:643] P bfe5919082ef460a978e3aebd8bd6f76: MajorDeltaCompactionOp(984a27d312f04e1d97a10e5e26552d1a) complete. Timing: real 0.150s	user 0.112s	sys 0.032s 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":431,"lbm_read_time_us":9943,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28062,"lbm_writes_lt_1ms":443,"mutex_wait_us":117,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":16768,"update_count":2000}
I20260812 06:20:26.707963 13958 maintenance_manager.cc:419] P bfe5919082ef460a978e3aebd8bd6f76: Scheduling FlushDeltaMemStoresOp(984a27d312f04e1d97a10e5e26552d1a): perf score=10.126437
I20260812 06:20:26.754977 13884 maintenance_manager.cc:643] P bfe5919082ef460a978e3aebd8bd6f76: FlushDeltaMemStoresOp(984a27d312f04e1d97a10e5e26552d1a) complete. Timing: real 0.047s	user 0.022s	sys 0.020s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":21434,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:20:26.755554 13958 maintenance_manager.cc:419] P bfe5919082ef460a978e3aebd8bd6f76: Scheduling FlushDeltaMemStoresOp(984a27d312f04e1d97a10e5e26552d1a): perf score=2.188937
I20260812 06:20:26.767351 13884 maintenance_manager.cc:643] P bfe5919082ef460a978e3aebd8bd6f76: FlushDeltaMemStoresOp(984a27d312f04e1d97a10e5e26552d1a) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4198,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:26.768383 13958 maintenance_manager.cc:419] P bfe5919082ef460a978e3aebd8bd6f76: Scheduling FlushMRSOp(984a27d312f04e1d97a10e5e26552d1a): perf score=1.000000
I20260812 06:20:26.800747 13884 maintenance_manager.cc:643] P bfe5919082ef460a978e3aebd8bd6f76: FlushMRSOp(984a27d312f04e1d97a10e5e26552d1a) complete. Timing: real 0.032s	user 0.031s	sys 0.001s Metrics: {"bytes_written":1275443,"cfile_init":1,"dirs.queue_time_us":67,"dirs.run_cpu_time_us":228,"dirs.run_wall_time_us":1460,"drs_written":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1738,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:20:26.801424 13958 maintenance_manager.cc:419] P bfe5919082ef460a978e3aebd8bd6f76: Scheduling LogGCOp(984a27d312f04e1d97a10e5e26552d1a): free 124257261 bytes of WAL
I20260812 06:20:26.801698 13884 log_reader.cc:385] T 984a27d312f04e1d97a10e5e26552d1a: removed 12 log segments from log reader
I20260812 06:20:26.801745 13884 log.cc:1079] T 984a27d312f04e1d97a10e5e26552d1a P bfe5919082ef460a978e3aebd8bd6f76: Deleting log segment in path: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618875398-13552-0/minicluster-data/ts-0-root/wals/984a27d312f04e1d97a10e5e26552d1a/wal-000000003 (ops 12-16)
I20260812 06:20:26.801775 13884 log.cc:1079] T 984a27d312f04e1d97a10e5e26552d1a P bfe5919082ef460a978e3aebd8bd6f76: Deleting log segment in path: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618875398-13552-0/minicluster-data/ts-0-root/wals/984a27d312f04e1d97a10e5e26552d1a/wal-000000004 (ops 17-21)
I20260812 06:20:26.801836 13884 log.cc:1079] T 984a27d312f04e1d97a10e5e26552d1a P bfe5919082ef460a978e3aebd8bd6f76: Deleting log segment in path: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618875398-13552-0/minicluster-data/ts-0-root/wals/984a27d312f04e1d97a10e5e26552d1a/wal-000000005 (ops 22-26)
I20260812 06:20:26.801880 13884 log.cc:1079] T 984a27d312f04e1d97a10e5e26552d1a P bfe5919082ef460a978e3aebd8bd6f76: Deleting log segment in path: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618875398-13552-0/minicluster-data/ts-0-root/wals/984a27d312f04e1d97a10e5e26552d1a/wal-000000006 (ops 27-30)
I20260812 06:20:26.801962 13884 log.cc:1079] T 984a27d312f04e1d97a10e5e26552d1a P bfe5919082ef460a978e3aebd8bd6f76: Deleting log segment in path: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618875398-13552-0/minicluster-data/ts-0-root/wals/984a27d312f04e1d97a10e5e26552d1a/wal-000000007 (ops 31-35)
I20260812 06:20:26.802022 13884 log.cc:1079] T 984a27d312f04e1d97a10e5e26552d1a P bfe5919082ef460a978e3aebd8bd6f76: Deleting log segment in path: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618875398-13552-0/minicluster-data/ts-0-root/wals/984a27d312f04e1d97a10e5e26552d1a/wal-000000008 (ops 36-40)
I20260812 06:20:26.802065 13884 log.cc:1079] T 984a27d312f04e1d97a10e5e26552d1a P bfe5919082ef460a978e3aebd8bd6f76: Deleting log segment in path: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618875398-13552-0/minicluster-data/ts-0-root/wals/984a27d312f04e1d97a10e5e26552d1a/wal-000000009 (ops 41-45)
I20260812 06:20:26.802105 13884 log.cc:1079] T 984a27d312f04e1d97a10e5e26552d1a P bfe5919082ef460a978e3aebd8bd6f76: Deleting log segment in path: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618875398-13552-0/minicluster-data/ts-0-root/wals/984a27d312f04e1d97a10e5e26552d1a/wal-000000010 (ops 46-50)
I20260812 06:20:26.802158 13884 log.cc:1079] T 984a27d312f04e1d97a10e5e26552d1a P bfe5919082ef460a978e3aebd8bd6f76: Deleting log segment in path: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618875398-13552-0/minicluster-data/ts-0-root/wals/984a27d312f04e1d97a10e5e26552d1a/wal-000000011 (ops 51-55)
I20260812 06:20:26.802201 13884 log.cc:1079] T 984a27d312f04e1d97a10e5e26552d1a P bfe5919082ef460a978e3aebd8bd6f76: Deleting log segment in path: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618875398-13552-0/minicluster-data/ts-0-root/wals/984a27d312f04e1d97a10e5e26552d1a/wal-000000012 (ops 56-60)
I20260812 06:20:26.802237 13884 log.cc:1079] T 984a27d312f04e1d97a10e5e26552d1a P bfe5919082ef460a978e3aebd8bd6f76: Deleting log segment in path: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618875398-13552-0/minicluster-data/ts-0-root/wals/984a27d312f04e1d97a10e5e26552d1a/wal-000000013 (ops 61-65)
I20260812 06:20:26.802275 13884 log.cc:1079] T 984a27d312f04e1d97a10e5e26552d1a P bfe5919082ef460a978e3aebd8bd6f76: Deleting log segment in path: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618875398-13552-0/minicluster-data/ts-0-root/wals/984a27d312f04e1d97a10e5e26552d1a/wal-000000014 (ops 66-70)
I20260812 06:20:26.831911 13884 maintenance_manager.cc:643] P bfe5919082ef460a978e3aebd8bd6f76: LogGCOp(984a27d312f04e1d97a10e5e26552d1a) complete. Timing: real 0.030s	user 0.001s	sys 0.028s Metrics: {}
I20260812 06:20:26.833281 13958 maintenance_manager.cc:419] P bfe5919082ef460a978e3aebd8bd6f76: Scheduling UndoDeltaBlockGCOp(984a27d312f04e1d97a10e5e26552d1a): 483 bytes on disk
I20260812 06:20:26.833734 13884 maintenance_manager.cc:643] P bfe5919082ef460a978e3aebd8bd6f76: UndoDeltaBlockGCOp(984a27d312f04e1d97a10e5e26552d1a) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":57,"lbm_reads_lt_1ms":4}
I20260812 06:20:26.834291 13958 maintenance_manager.cc:419] P bfe5919082ef460a978e3aebd8bd6f76: Scheduling FlushDeltaMemStoresOp(984a27d312f04e1d97a10e5e26552d1a): perf score=4.173312
I20260812 06:20:26.848664 13884 maintenance_manager.cc:643] P bfe5919082ef460a978e3aebd8bd6f76: FlushDeltaMemStoresOp(984a27d312f04e1d97a10e5e26552d1a) complete. Timing: real 0.014s	user 0.010s	sys 0.004s Metrics: {"bytes_written":5620561,"delete_count":0,"lbm_write_time_us":5856,"lbm_writes_lt_1ms":140,"reinsert_count":0,"update_count":685}
I20260812 06:20:26.849121 13958 maintenance_manager.cc:419] P bfe5919082ef460a978e3aebd8bd6f76: Scheduling FlushDeltaMemStoresOp(984a27d312f04e1d97a10e5e26552d1a): perf score=1.196750
I20260812 06:20:26.858633 13884 maintenance_manager.cc:643] P bfe5919082ef460a978e3aebd8bd6f76: FlushDeltaMemStoresOp(984a27d312f04e1d97a10e5e26552d1a) complete. Timing: real 0.009s	user 0.002s	sys 0.004s Metrics: {"bytes_written":2584729,"delete_count":0,"lbm_write_time_us":2988,"lbm_writes_lt_1ms":66,"reinsert_count":0,"update_count":315}
I20260812 06:20:26.859266 13958 maintenance_manager.cc:419] P bfe5919082ef460a978e3aebd8bd6f76: Scheduling MajorDeltaCompactionOp(984a27d312f04e1d97a10e5e26552d1a): perf score=1.000000
I20260812 06:20:27.055867 13884 maintenance_manager.cc:643] P bfe5919082ef460a978e3aebd8bd6f76: MajorDeltaCompactionOp(984a27d312f04e1d97a10e5e26552d1a) complete. Timing: real 0.196s	user 0.123s	sys 0.072s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877307,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":2673,"lbm_read_time_us":14684,"lbm_reads_lt_1ms":674,"lbm_write_time_us":36365,"lbm_writes_lt_1ms":643,"mutex_wait_us":1095,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":25344,"thread_start_us":103,"threads_started":1,"update_count":3000}
I20260812 06:20:27.056843 13958 maintenance_manager.cc:419] P bfe5919082ef460a978e3aebd8bd6f76: Scheduling FlushDeltaMemStoresOp(984a27d312f04e1d97a10e5e26552d1a): perf score=14.095187
I20260812 06:20:27.105691 13884 maintenance_manager.cc:643] P bfe5919082ef460a978e3aebd8bd6f76: FlushDeltaMemStoresOp(984a27d312f04e1d97a10e5e26552d1a) complete. Timing: real 0.049s	user 0.035s	sys 0.012s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":21136,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:27.106276 13958 maintenance_manager.cc:419] P bfe5919082ef460a978e3aebd8bd6f76: Scheduling FlushDeltaMemStoresOp(984a27d312f04e1d97a10e5e26552d1a): perf score=2.188937
I20260812 06:20:27.124787 13884 maintenance_manager.cc:643] P bfe5919082ef460a978e3aebd8bd6f76: FlushDeltaMemStoresOp(984a27d312f04e1d97a10e5e26552d1a) complete. Timing: real 0.018s	user 0.017s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6806,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:27.125450 13958 maintenance_manager.cc:419] P bfe5919082ef460a978e3aebd8bd6f76: Scheduling MajorDeltaCompactionOp(984a27d312f04e1d97a10e5e26552d1a): perf score=1.000000
I20260812 06:20:27.309855 13884 maintenance_manager.cc:643] P bfe5919082ef460a978e3aebd8bd6f76: MajorDeltaCompactionOp(984a27d312f04e1d97a10e5e26552d1a) complete. Timing: real 0.184s	user 0.111s	sys 0.063s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":619,"lbm_read_time_us":13510,"lbm_reads_lt_1ms":564,"lbm_write_time_us":33714,"lbm_writes_lt_1ms":543,"mutex_wait_us":296,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":76928,"update_count":2500}
I20260812 06:20:27.310612 13958 maintenance_manager.cc:419] P bfe5919082ef460a978e3aebd8bd6f76: Scheduling FlushDeltaMemStoresOp(984a27d312f04e1d97a10e5e26552d1a): perf score=14.095187
I20260812 06:20:27.377522 13884 maintenance_manager.cc:643] P bfe5919082ef460a978e3aebd8bd6f76: FlushDeltaMemStoresOp(984a27d312f04e1d97a10e5e26552d1a) complete. Timing: real 0.067s	user 0.030s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24094,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:27.378104 13958 maintenance_manager.cc:419] P bfe5919082ef460a978e3aebd8bd6f76: Scheduling FlushDeltaMemStoresOp(984a27d312f04e1d97a10e5e26552d1a): perf score=2.188937
I20260812 06:20:27.391098 13884 maintenance_manager.cc:643] P bfe5919082ef460a978e3aebd8bd6f76: FlushDeltaMemStoresOp(984a27d312f04e1d97a10e5e26552d1a) complete. Timing: real 0.013s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4696,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:27.391640 13958 maintenance_manager.cc:419] P bfe5919082ef460a978e3aebd8bd6f76: Scheduling MajorDeltaCompactionOp(984a27d312f04e1d97a10e5e26552d1a): perf score=1.000000
I20260812 06:20:27.583612 13884 maintenance_manager.cc:643] P bfe5919082ef460a978e3aebd8bd6f76: MajorDeltaCompactionOp(984a27d312f04e1d97a10e5e26552d1a) complete. Timing: real 0.192s	user 0.120s	sys 0.064s 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":176,"lbm_read_time_us":13779,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33858,"lbm_writes_lt_1ms":543,"mutex_wait_us":26,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":38144,"update_count":2500}
I20260812 06:20:27.584348 13958 maintenance_manager.cc:419] P bfe5919082ef460a978e3aebd8bd6f76: Scheduling FlushDeltaMemStoresOp(984a27d312f04e1d97a10e5e26552d1a): perf score=14.095187
I20260812 06:20:27.652213 13884 maintenance_manager.cc:643] P bfe5919082ef460a978e3aebd8bd6f76: FlushDeltaMemStoresOp(984a27d312f04e1d97a10e5e26552d1a) complete. Timing: real 0.068s	user 0.032s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22614,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:27.652954 13958 maintenance_manager.cc:419] P bfe5919082ef460a978e3aebd8bd6f76: Scheduling FlushDeltaMemStoresOp(984a27d312f04e1d97a10e5e26552d1a): perf score=2.188937
I20260812 06:20:27.673169 13884 maintenance_manager.cc:643] P bfe5919082ef460a978e3aebd8bd6f76: FlushDeltaMemStoresOp(984a27d312f04e1d97a10e5e26552d1a) complete. Timing: real 0.019s	user 0.011s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":7370,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:27.673874 13958 maintenance_manager.cc:419] P bfe5919082ef460a978e3aebd8bd6f76: Scheduling MajorDeltaCompactionOp(984a27d312f04e1d97a10e5e26552d1a): perf score=1.000000
I20260812 06:20:27.968295 13884 maintenance_manager.cc:643] P bfe5919082ef460a978e3aebd8bd6f76: MajorDeltaCompactionOp(984a27d312f04e1d97a10e5e26552d1a) complete. Timing: real 0.294s	user 0.208s	sys 0.079s 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":827,"lbm_read_time_us":19506,"lbm_reads_lt_1ms":572,"lbm_write_time_us":41986,"lbm_writes_lt_1ms":543,"mutex_wait_us":340,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2500}
I20260812 06:20:27.969154 13958 maintenance_manager.cc:419] P bfe5919082ef460a978e3aebd8bd6f76: Scheduling FlushDeltaMemStoresOp(984a27d312f04e1d97a10e5e26552d1a): perf score=24.017062
I20260812 06:20:28.070392 13884 maintenance_manager.cc:643] P bfe5919082ef460a978e3aebd8bd6f76: FlushDeltaMemStoresOp(984a27d312f04e1d97a10e5e26552d1a) complete. Timing: real 0.101s	user 0.038s	sys 0.039s Metrics: {"bytes_written":25845451,"delete_count":0,"lbm_write_time_us":36101,"lbm_writes_lt_1ms":633,"reinsert_count":0,"update_count":3150}
I20260812 06:20:28.071170 13958 maintenance_manager.cc:419] P bfe5919082ef460a978e3aebd8bd6f76: Scheduling FlushDeltaMemStoresOp(984a27d312f04e1d97a10e5e26552d1a): perf score=5.165500
I20260812 06:20:28.115229 13884 maintenance_manager.cc:643] P bfe5919082ef460a978e3aebd8bd6f76: FlushDeltaMemStoresOp(984a27d312f04e1d97a10e5e26552d1a) complete. Timing: real 0.044s	user 0.012s	sys 0.015s Metrics: {"bytes_written":6974357,"delete_count":0,"lbm_write_time_us":12143,"lbm_writes_lt_1ms":173,"reinsert_count":0,"update_count":850}
I20260812 06:20:28.115957 13958 maintenance_manager.cc:419] P bfe5919082ef460a978e3aebd8bd6f76: Scheduling FlushDeltaMemStoresOp(984a27d312f04e1d97a10e5e26552d1a): perf score=2.188937
I20260812 06:20:28.135044 13884 maintenance_manager.cc:643] P bfe5919082ef460a978e3aebd8bd6f76: FlushDeltaMemStoresOp(984a27d312f04e1d97a10e5e26552d1a) complete. Timing: real 0.019s	user 0.008s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":7023,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:28.135766 13958 maintenance_manager.cc:419] P bfe5919082ef460a978e3aebd8bd6f76: Scheduling MajorDeltaCompactionOp(984a27d312f04e1d97a10e5e26552d1a): perf score=1.000000
I20260812 06:20:28.418912 13884 maintenance_manager.cc:643] P bfe5919082ef460a978e3aebd8bd6f76: MajorDeltaCompactionOp(984a27d312f04e1d97a10e5e26552d1a) complete. Timing: real 0.283s	user 0.177s	sys 0.099s Metrics: {"cfile_cache_miss":933,"cfile_cache_miss_bytes":41184460,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1076,"lbm_read_time_us":20885,"lbm_reads_lt_1ms":973,"lbm_write_time_us":51757,"lbm_writes_lt_1ms":943,"mutex_wait_us":22,"peak_mem_usage":112822188,"reinsert_count":0,"spinlock_wait_cycles":15104,"update_count":4500}
I20260812 06:20:28.419878 13958 maintenance_manager.cc:419] P bfe5919082ef460a978e3aebd8bd6f76: Scheduling FlushDeltaMemStoresOp(984a27d312f04e1d97a10e5e26552d1a): perf score=22.032687
I20260812 06:20:28.497674 13884 maintenance_manager.cc:643] P bfe5919082ef460a978e3aebd8bd6f76: FlushDeltaMemStoresOp(984a27d312f04e1d97a10e5e26552d1a) complete. Timing: real 0.078s	user 0.048s	sys 0.027s Metrics: {"bytes_written":24614722,"delete_count":0,"lbm_write_time_us":34390,"lbm_writes_lt_1ms":603,"reinsert_count":0,"update_count":3000}
I20260812 06:20:28.498230 13958 maintenance_manager.cc:419] P bfe5919082ef460a978e3aebd8bd6f76: Scheduling FlushDeltaMemStoresOp(984a27d312f04e1d97a10e5e26552d1a): perf score=2.188937
I20260812 06:20:28.527245 13884 maintenance_manager.cc:643] P bfe5919082ef460a978e3aebd8bd6f76: FlushDeltaMemStoresOp(984a27d312f04e1d97a10e5e26552d1a) complete. Timing: real 0.029s	user 0.004s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7342,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:28.527777 13958 maintenance_manager.cc:419] P bfe5919082ef460a978e3aebd8bd6f76: Scheduling FlushDeltaMemStoresOp(984a27d312f04e1d97a10e5e26552d1a): perf score=2.188937
I20260812 06:20:28.539862 13884 maintenance_manager.cc:643] P bfe5919082ef460a978e3aebd8bd6f76: FlushDeltaMemStoresOp(984a27d312f04e1d97a10e5e26552d1a) complete. Timing: real 0.012s	user 0.000s	sys 0.010s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4786,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:28.540766 13958 maintenance_manager.cc:419] P bfe5919082ef460a978e3aebd8bd6f76: Scheduling FlushMRSOp(984a27d312f04e1d97a10e5e26552d1a): perf score=1.000000
I20260812 06:20:28.580291 13884 maintenance_manager.cc:643] P bfe5919082ef460a978e3aebd8bd6f76: FlushMRSOp(984a27d312f04e1d97a10e5e26552d1a) complete. Timing: real 0.039s	user 0.037s	sys 0.000s Metrics: {"bytes_written":1398560,"cfile_init":1,"dirs.queue_time_us":89,"dirs.run_cpu_time_us":258,"dirs.run_wall_time_us":1823,"drs_written":1,"lbm_read_time_us":44,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2004,"lbm_writes_lt_1ms":44,"peak_mem_usage":0,"rows_written":34}
I20260812 06:20:28.581133 13958 maintenance_manager.cc:419] P bfe5919082ef460a978e3aebd8bd6f76: Scheduling LogGCOp(984a27d312f04e1d97a10e5e26552d1a): free 142244606 bytes of WAL
I20260812 06:20:28.581459 13884 log_reader.cc:385] T 984a27d312f04e1d97a10e5e26552d1a: removed 14 log segments from log reader
I20260812 06:20:28.581593 13884 log.cc:1079] T 984a27d312f04e1d97a10e5e26552d1a P bfe5919082ef460a978e3aebd8bd6f76: Deleting log segment in path: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618875398-13552-0/minicluster-data/ts-0-root/wals/984a27d312f04e1d97a10e5e26552d1a/wal-000000015 (ops 71-75)
I20260812 06:20:28.581657 13884 log.cc:1079] T 984a27d312f04e1d97a10e5e26552d1a P bfe5919082ef460a978e3aebd8bd6f76: Deleting log segment in path: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618875398-13552-0/minicluster-data/ts-0-root/wals/984a27d312f04e1d97a10e5e26552d1a/wal-000000016 (ops 76-80)
I20260812 06:20:28.581724 13884 log.cc:1079] T 984a27d312f04e1d97a10e5e26552d1a P bfe5919082ef460a978e3aebd8bd6f76: Deleting log segment in path: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618875398-13552-0/minicluster-data/ts-0-root/wals/984a27d312f04e1d97a10e5e26552d1a/wal-000000017 (ops 81-85)
I20260812 06:20:28.581774 13884 log.cc:1079] T 984a27d312f04e1d97a10e5e26552d1a P bfe5919082ef460a978e3aebd8bd6f76: Deleting log segment in path: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618875398-13552-0/minicluster-data/ts-0-root/wals/984a27d312f04e1d97a10e5e26552d1a/wal-000000018 (ops 86-90)
I20260812 06:20:28.581815 13884 log.cc:1079] T 984a27d312f04e1d97a10e5e26552d1a P bfe5919082ef460a978e3aebd8bd6f76: Deleting log segment in path: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618875398-13552-0/minicluster-data/ts-0-root/wals/984a27d312f04e1d97a10e5e26552d1a/wal-000000019 (ops 91-95)
I20260812 06:20:28.581861 13884 log.cc:1079] T 984a27d312f04e1d97a10e5e26552d1a P bfe5919082ef460a978e3aebd8bd6f76: Deleting log segment in path: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618875398-13552-0/minicluster-data/ts-0-root/wals/984a27d312f04e1d97a10e5e26552d1a/wal-000000020 (ops 96-100)
I20260812 06:20:28.581904 13884 log.cc:1079] T 984a27d312f04e1d97a10e5e26552d1a P bfe5919082ef460a978e3aebd8bd6f76: Deleting log segment in path: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618875398-13552-0/minicluster-data/ts-0-root/wals/984a27d312f04e1d97a10e5e26552d1a/wal-000000021 (ops 101-105)
I20260812 06:20:28.581948 13884 log.cc:1079] T 984a27d312f04e1d97a10e5e26552d1a P bfe5919082ef460a978e3aebd8bd6f76: Deleting log segment in path: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618875398-13552-0/minicluster-data/ts-0-root/wals/984a27d312f04e1d97a10e5e26552d1a/wal-000000022 (ops 106-110)
I20260812 06:20:28.581991 13884 log.cc:1079] T 984a27d312f04e1d97a10e5e26552d1a P bfe5919082ef460a978e3aebd8bd6f76: Deleting log segment in path: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618875398-13552-0/minicluster-data/ts-0-root/wals/984a27d312f04e1d97a10e5e26552d1a/wal-000000023 (ops 111-115)
I20260812 06:20:28.582042 13884 log.cc:1079] T 984a27d312f04e1d97a10e5e26552d1a P bfe5919082ef460a978e3aebd8bd6f76: Deleting log segment in path: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618875398-13552-0/minicluster-data/ts-0-root/wals/984a27d312f04e1d97a10e5e26552d1a/wal-000000024 (ops 116-120)
I20260812 06:20:28.582083 13884 log.cc:1079] T 984a27d312f04e1d97a10e5e26552d1a P bfe5919082ef460a978e3aebd8bd6f76: Deleting log segment in path: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618875398-13552-0/minicluster-data/ts-0-root/wals/984a27d312f04e1d97a10e5e26552d1a/wal-000000025 (ops 121-125)
I20260812 06:20:28.582129 13884 log.cc:1079] T 984a27d312f04e1d97a10e5e26552d1a P bfe5919082ef460a978e3aebd8bd6f76: Deleting log segment in path: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618875398-13552-0/minicluster-data/ts-0-root/wals/984a27d312f04e1d97a10e5e26552d1a/wal-000000026 (ops 126-130)
I20260812 06:20:28.582190 13884 log.cc:1079] T 984a27d312f04e1d97a10e5e26552d1a P bfe5919082ef460a978e3aebd8bd6f76: Deleting log segment in path: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618875398-13552-0/minicluster-data/ts-0-root/wals/984a27d312f04e1d97a10e5e26552d1a/wal-000000027 (ops 131-135)
I20260812 06:20:28.582227 13884 log.cc:1079] T 984a27d312f04e1d97a10e5e26552d1a P bfe5919082ef460a978e3aebd8bd6f76: Deleting log segment in path: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618875398-13552-0/minicluster-data/ts-0-root/wals/984a27d312f04e1d97a10e5e26552d1a/wal-000000028 (ops 136-140)
I20260812 06:20:28.621244 13884 maintenance_manager.cc:643] P bfe5919082ef460a978e3aebd8bd6f76: LogGCOp(984a27d312f04e1d97a10e5e26552d1a) complete. Timing: real 0.040s	user 0.004s	sys 0.035s Metrics: {}
I20260812 06:20:28.621831 13958 maintenance_manager.cc:419] P bfe5919082ef460a978e3aebd8bd6f76: Scheduling UndoDeltaBlockGCOp(984a27d312f04e1d97a10e5e26552d1a): 517 bytes on disk
I20260812 06:20:28.622349 13884 maintenance_manager.cc:643] P bfe5919082ef460a978e3aebd8bd6f76: UndoDeltaBlockGCOp(984a27d312f04e1d97a10e5e26552d1a) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":80,"lbm_reads_lt_1ms":4}
I20260812 06:20:28.622962 13958 maintenance_manager.cc:419] P bfe5919082ef460a978e3aebd8bd6f76: Scheduling FlushDeltaMemStoresOp(984a27d312f04e1d97a10e5e26552d1a): perf score=6.157687
I20260812 06:20:28.644115 13884 maintenance_manager.cc:643] P bfe5919082ef460a978e3aebd8bd6f76: FlushDeltaMemStoresOp(984a27d312f04e1d97a10e5e26552d1a) complete. Timing: real 0.021s	user 0.009s	sys 0.008s Metrics: {"bytes_written":7384593,"delete_count":0,"lbm_write_time_us":8034,"lbm_writes_lt_1ms":183,"reinsert_count":0,"update_count":900}
I20260812 06:20:28.644727 13958 maintenance_manager.cc:419] P bfe5919082ef460a978e3aebd8bd6f76: Scheduling MajorDeltaCompactionOp(984a27d312f04e1d97a10e5e26552d1a): perf score=1.000000
I20260812 06:20:28.960002 13884 maintenance_manager.cc:643] P bfe5919082ef460a978e3aebd8bd6f76: MajorDeltaCompactionOp(984a27d312f04e1d97a10e5e26552d1a) complete. Timing: real 0.315s	user 0.238s	sys 0.065s Metrics: {"cfile_cache_miss":1014,"cfile_cache_miss_bytes":44466499,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1065,"lbm_read_time_us":19566,"lbm_reads_lt_1ms":1050,"lbm_write_time_us":55169,"lbm_writes_lt_1ms":1023,"mutex_wait_us":329,"peak_mem_usage":122347292,"reinsert_count":0,"spinlock_wait_cycles":16768,"thread_start_us":461,"threads_started":6,"update_count":4900}
I20260812 06:20:28.960991 13958 maintenance_manager.cc:419] P bfe5919082ef460a978e3aebd8bd6f76: Scheduling FlushDeltaMemStoresOp(984a27d312f04e1d97a10e5e26552d1a): perf score=23.024875
I20260812 06:20:29.046895 13884 maintenance_manager.cc:643] P bfe5919082ef460a978e3aebd8bd6f76: FlushDeltaMemStoresOp(984a27d312f04e1d97a10e5e26552d1a) complete. Timing: real 0.086s	user 0.061s	sys 0.019s Metrics: {"bytes_written":25435216,"delete_count":0,"lbm_write_time_us":38213,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":622,"reinsert_count":0,"update_count":3100}
I20260812 06:20:29.047613 13958 maintenance_manager.cc:419] P bfe5919082ef460a978e3aebd8bd6f76: Scheduling FlushDeltaMemStoresOp(984a27d312f04e1d97a10e5e26552d1a): perf score=2.188937
I20260812 06:20:29.061604 13884 maintenance_manager.cc:643] P bfe5919082ef460a978e3aebd8bd6f76: FlushDeltaMemStoresOp(984a27d312f04e1d97a10e5e26552d1a) complete. Timing: real 0.014s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4836,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:29.062196 13958 maintenance_manager.cc:419] P bfe5919082ef460a978e3aebd8bd6f76: Scheduling MajorDeltaCompactionOp(984a27d312f04e1d97a10e5e26552d1a): perf score=1.000000
I20260812 06:20:29.312660 13884 maintenance_manager.cc:643] P bfe5919082ef460a978e3aebd8bd6f76: MajorDeltaCompactionOp(984a27d312f04e1d97a10e5e26552d1a) complete. Timing: real 0.250s	user 0.151s	sys 0.096s Metrics: {"cfile_cache_miss":752,"cfile_cache_miss_bytes":33800003,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1301,"lbm_read_time_us":15916,"lbm_reads_lt_1ms":792,"lbm_write_time_us":44007,"lbm_writes_lt_1ms":763,"mutex_wait_us":132,"peak_mem_usage":89830128,"reinsert_count":0,"spinlock_wait_cycles":18432,"update_count":3600}
I20260812 06:20:29.313544 13958 maintenance_manager.cc:419] P bfe5919082ef460a978e3aebd8bd6f76: Scheduling FlushDeltaMemStoresOp(984a27d312f04e1d97a10e5e26552d1a): perf score=18.063937
I20260812 06:20:29.377345 13884 maintenance_manager.cc:643] P bfe5919082ef460a978e3aebd8bd6f76: FlushDeltaMemStoresOp(984a27d312f04e1d97a10e5e26552d1a) complete. Timing: real 0.063s	user 0.040s	sys 0.022s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":28649,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:29.377871 13958 maintenance_manager.cc:419] P bfe5919082ef460a978e3aebd8bd6f76: Scheduling FlushDeltaMemStoresOp(984a27d312f04e1d97a10e5e26552d1a): perf score=2.188937
I20260812 06:20:29.402392 13884 maintenance_manager.cc:643] P bfe5919082ef460a978e3aebd8bd6f76: FlushDeltaMemStoresOp(984a27d312f04e1d97a10e5e26552d1a) complete. Timing: real 0.024s	user 0.010s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6179,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:29.402998 13958 maintenance_manager.cc:419] P bfe5919082ef460a978e3aebd8bd6f76: Scheduling FlushDeltaMemStoresOp(984a27d312f04e1d97a10e5e26552d1a): perf score=2.188937
I20260812 06:20:29.415151 13884 maintenance_manager.cc:643] P bfe5919082ef460a978e3aebd8bd6f76: FlushDeltaMemStoresOp(984a27d312f04e1d97a10e5e26552d1a) complete. Timing: real 0.012s	user 0.003s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4646,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:29.415714 13958 maintenance_manager.cc:419] P bfe5919082ef460a978e3aebd8bd6f76: Scheduling MajorDeltaCompactionOp(984a27d312f04e1d97a10e5e26552d1a): perf score=1.000000
I20260812 06:20:29.620398 13884 maintenance_manager.cc:643] P bfe5919082ef460a978e3aebd8bd6f76: MajorDeltaCompactionOp(984a27d312f04e1d97a10e5e26552d1a) complete. Timing: real 0.204s	user 0.166s	sys 0.035s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":32979634,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":121,"lbm_read_time_us":15027,"lbm_reads_lt_1ms":773,"lbm_write_time_us":42750,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":3584,"update_count":3500}
I20260812 06:20:29.621157 13958 maintenance_manager.cc:419] P bfe5919082ef460a978e3aebd8bd6f76: Scheduling FlushDeltaMemStoresOp(984a27d312f04e1d97a10e5e26552d1a): perf score=14.095187
I20260812 06:20:29.668576 13884 maintenance_manager.cc:643] P bfe5919082ef460a978e3aebd8bd6f76: FlushDeltaMemStoresOp(984a27d312f04e1d97a10e5e26552d1a) complete. Timing: real 0.047s	user 0.014s	sys 0.031s Metrics: {"bytes_written":16409899,"delete_count":0,"lbm_write_time_us":22257,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:29.669278 13958 maintenance_manager.cc:419] P bfe5919082ef460a978e3aebd8bd6f76: Scheduling FlushDeltaMemStoresOp(984a27d312f04e1d97a10e5e26552d1a): perf score=2.188937
I20260812 06:20:29.689085 13884 maintenance_manager.cc:643] P bfe5919082ef460a978e3aebd8bd6f76: FlushDeltaMemStoresOp(984a27d312f04e1d97a10e5e26552d1a) complete. Timing: real 0.019s	user 0.016s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7323,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":102,"reinsert_count":0,"update_count":500}
I20260812 06:20:29.690256 13958 maintenance_manager.cc:419] P bfe5919082ef460a978e3aebd8bd6f76: Scheduling MajorDeltaCompactionOp(984a27d312f04e1d97a10e5e26552d1a): perf score=1.000000
I20260812 06:20:29.864216 13884 maintenance_manager.cc:643] P bfe5919082ef460a978e3aebd8bd6f76: MajorDeltaCompactionOp(984a27d312f04e1d97a10e5e26552d1a) complete. Timing: real 0.174s	user 0.133s	sys 0.031s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774686,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":986,"lbm_read_time_us":9656,"lbm_reads_lt_1ms":564,"lbm_write_time_us":31934,"lbm_writes_lt_1ms":543,"mutex_wait_us":411,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9728,"update_count":2500}
I20260812 06:20:29.865005 13958 maintenance_manager.cc:419] P bfe5919082ef460a978e3aebd8bd6f76: Scheduling FlushDeltaMemStoresOp(984a27d312f04e1d97a10e5e26552d1a): perf score=14.095187
I20260812 06:20:29.923790 13884 maintenance_manager.cc:643] P bfe5919082ef460a978e3aebd8bd6f76: FlushDeltaMemStoresOp(984a27d312f04e1d97a10e5e26552d1a) complete. Timing: real 0.059s	user 0.036s	sys 0.020s Metrics: {"bytes_written":16409909,"delete_count":0,"lbm_write_time_us":26233,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:29.924363 13958 maintenance_manager.cc:419] P bfe5919082ef460a978e3aebd8bd6f76: Scheduling MajorDeltaCompactionOp(984a27d312f04e1d97a10e5e26552d1a): perf score=1.000000
I20260812 06:20:30.075515 13884 maintenance_manager.cc:643] P bfe5919082ef460a978e3aebd8bd6f76: MajorDeltaCompactionOp(984a27d312f04e1d97a10e5e26552d1a) complete. Timing: real 0.151s	user 0.086s	sys 0.064s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672165,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":374,"lbm_read_time_us":9606,"lbm_reads_lt_1ms":467,"lbm_write_time_us":26710,"lbm_writes_lt_1ms":443,"mutex_wait_us":92,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6144,"update_count":2000}
I20260812 06:20:30.076105 13958 maintenance_manager.cc:419] P bfe5919082ef460a978e3aebd8bd6f76: Scheduling FlushDeltaMemStoresOp(984a27d312f04e1d97a10e5e26552d1a): perf score=10.126437
I20260812 06:20:30.118359 13884 maintenance_manager.cc:643] P bfe5919082ef460a978e3aebd8bd6f76: FlushDeltaMemStoresOp(984a27d312f04e1d97a10e5e26552d1a) complete. Timing: real 0.042s	user 0.033s	sys 0.004s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17117,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:30.118948 13958 maintenance_manager.cc:419] P bfe5919082ef460a978e3aebd8bd6f76: Scheduling FlushDeltaMemStoresOp(984a27d312f04e1d97a10e5e26552d1a): perf score=2.188937
I20260812 06:20:30.130177 13884 maintenance_manager.cc:643] P bfe5919082ef460a978e3aebd8bd6f76: FlushDeltaMemStoresOp(984a27d312f04e1d97a10e5e26552d1a) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4440,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:30.130805 13958 maintenance_manager.cc:419] P bfe5919082ef460a978e3aebd8bd6f76: Scheduling FlushMRSOp(984a27d312f04e1d97a10e5e26552d1a): perf score=1.000000
I20260812 06:20:30.165650 13884 maintenance_manager.cc:643] P bfe5919082ef460a978e3aebd8bd6f76: FlushMRSOp(984a27d312f04e1d97a10e5e26552d1a) complete. Timing: real 0.035s	user 0.032s	sys 0.000s Metrics: {"bytes_written":1193507,"cfile_init":1,"dirs.queue_time_us":105,"dirs.run_cpu_time_us":280,"dirs.run_wall_time_us":1644,"drs_written":1,"lbm_read_time_us":68,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2138,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:20:30.166373 13958 maintenance_manager.cc:419] P bfe5919082ef460a978e3aebd8bd6f76: Scheduling LogGCOp(984a27d312f04e1d97a10e5e26552d1a): free 124257457 bytes of WAL
I20260812 06:20:30.166617 13884 log_reader.cc:385] T 984a27d312f04e1d97a10e5e26552d1a: removed 12 log segments from log reader
I20260812 06:20:30.166669 13884 log.cc:1079] T 984a27d312f04e1d97a10e5e26552d1a P bfe5919082ef460a978e3aebd8bd6f76: Deleting log segment in path: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618875398-13552-0/minicluster-data/ts-0-root/wals/984a27d312f04e1d97a10e5e26552d1a/wal-000000029 (ops 141-144)
I20260812 06:20:30.166700 13884 log.cc:1079] T 984a27d312f04e1d97a10e5e26552d1a P bfe5919082ef460a978e3aebd8bd6f76: Deleting log segment in path: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618875398-13552-0/minicluster-data/ts-0-root/wals/984a27d312f04e1d97a10e5e26552d1a/wal-000000030 (ops 145-149)
I20260812 06:20:30.166764 13884 log.cc:1079] T 984a27d312f04e1d97a10e5e26552d1a P bfe5919082ef460a978e3aebd8bd6f76: Deleting log segment in path: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618875398-13552-0/minicluster-data/ts-0-root/wals/984a27d312f04e1d97a10e5e26552d1a/wal-000000031 (ops 150-154)
I20260812 06:20:30.166813 13884 log.cc:1079] T 984a27d312f04e1d97a10e5e26552d1a P bfe5919082ef460a978e3aebd8bd6f76: Deleting log segment in path: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618875398-13552-0/minicluster-data/ts-0-root/wals/984a27d312f04e1d97a10e5e26552d1a/wal-000000032 (ops 155-159)
I20260812 06:20:30.166832 13884 log.cc:1079] T 984a27d312f04e1d97a10e5e26552d1a P bfe5919082ef460a978e3aebd8bd6f76: Deleting log segment in path: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618875398-13552-0/minicluster-data/ts-0-root/wals/984a27d312f04e1d97a10e5e26552d1a/wal-000000033 (ops 160-164)
I20260812 06:20:30.166890 13884 log.cc:1079] T 984a27d312f04e1d97a10e5e26552d1a P bfe5919082ef460a978e3aebd8bd6f76: Deleting log segment in path: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618875398-13552-0/minicluster-data/ts-0-root/wals/984a27d312f04e1d97a10e5e26552d1a/wal-000000034 (ops 165-169)
I20260812 06:20:30.166944 13884 log.cc:1079] T 984a27d312f04e1d97a10e5e26552d1a P bfe5919082ef460a978e3aebd8bd6f76: Deleting log segment in path: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618875398-13552-0/minicluster-data/ts-0-root/wals/984a27d312f04e1d97a10e5e26552d1a/wal-000000035 (ops 170-174)
I20260812 06:20:30.166982 13884 log.cc:1079] T 984a27d312f04e1d97a10e5e26552d1a P bfe5919082ef460a978e3aebd8bd6f76: Deleting log segment in path: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618875398-13552-0/minicluster-data/ts-0-root/wals/984a27d312f04e1d97a10e5e26552d1a/wal-000000036 (ops 175-179)
I20260812 06:20:30.167016 13884 log.cc:1079] T 984a27d312f04e1d97a10e5e26552d1a P bfe5919082ef460a978e3aebd8bd6f76: Deleting log segment in path: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618875398-13552-0/minicluster-data/ts-0-root/wals/984a27d312f04e1d97a10e5e26552d1a/wal-000000037 (ops 180-184)
I20260812 06:20:30.167073 13884 log.cc:1079] T 984a27d312f04e1d97a10e5e26552d1a P bfe5919082ef460a978e3aebd8bd6f76: Deleting log segment in path: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618875398-13552-0/minicluster-data/ts-0-root/wals/984a27d312f04e1d97a10e5e26552d1a/wal-000000038 (ops 185-189)
I20260812 06:20:30.167116 13884 log.cc:1079] T 984a27d312f04e1d97a10e5e26552d1a P bfe5919082ef460a978e3aebd8bd6f76: Deleting log segment in path: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618875398-13552-0/minicluster-data/ts-0-root/wals/984a27d312f04e1d97a10e5e26552d1a/wal-000000039 (ops 190-194)
I20260812 06:20:30.167147 13884 log.cc:1079] T 984a27d312f04e1d97a10e5e26552d1a P bfe5919082ef460a978e3aebd8bd6f76: Deleting log segment in path: /tmp/dist-test-taskHynlFU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618875398-13552-0/minicluster-data/ts-0-root/wals/984a27d312f04e1d97a10e5e26552d1a/wal-000000040 (ops 195-199)
I20260812 06:20:30.196213 13884 maintenance_manager.cc:643] P bfe5919082ef460a978e3aebd8bd6f76: LogGCOp(984a27d312f04e1d97a10e5e26552d1a) complete. Timing: real 0.030s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:20:30.196740 13958 maintenance_manager.cc:419] P bfe5919082ef460a978e3aebd8bd6f76: Scheduling UndoDeltaBlockGCOp(984a27d312f04e1d97a10e5e26552d1a): 463 bytes on disk
I20260812 06:20:30.197211 13884 maintenance_manager.cc:643] P bfe5919082ef460a978e3aebd8bd6f76: UndoDeltaBlockGCOp(984a27d312f04e1d97a10e5e26552d1a) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4}
I20260812 06:20:30.198096 13958 maintenance_manager.cc:419] P bfe5919082ef460a978e3aebd8bd6f76: Scheduling FlushDeltaMemStoresOp(984a27d312f04e1d97a10e5e26552d1a): perf score=2.188937
I20260812 06:20:30.218003 13552 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.194s	user 1.873s	sys 0.158s
I20260812 06:20:30.228024 13884 maintenance_manager.cc:643] P bfe5919082ef460a978e3aebd8bd6f76: FlushDeltaMemStoresOp(984a27d312f04e1d97a10e5e26552d1a) complete. Timing: real 0.030s	user 0.007s	sys 0.012s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6764,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:30.228832 13958 maintenance_manager.cc:419] P bfe5919082ef460a978e3aebd8bd6f76: Scheduling FlushDeltaMemStoresOp(984a27d312f04e1d97a10e5e26552d1a): perf score=2.188937
I20260812 06:20:30.247661 13884 maintenance_manager.cc:643] P bfe5919082ef460a978e3aebd8bd6f76: FlushDeltaMemStoresOp(984a27d312f04e1d97a10e5e26552d1a) complete. Timing: real 0.019s	user 0.005s	sys 0.012s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":7498,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:30.248351 13958 maintenance_manager.cc:419] P bfe5919082ef460a978e3aebd8bd6f76: Scheduling MajorDeltaCompactionOp(984a27d312f04e1d97a10e5e26552d1a): perf score=1.000000
I20260812 06:20:30.337747 13552 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.119s	user 0.002s	sys 0.000s
I20260812 06:20:30.338299 13552 tablet_server.cc:179] TabletServer@127.13.60.1:0 shutting down...
I20260812 06:20:30.425073 13884 maintenance_manager.cc:643] P bfe5919082ef460a978e3aebd8bd6f76: MajorDeltaCompactionOp(984a27d312f04e1d97a10e5e26552d1a) complete. Timing: real 0.176s	user 0.120s	sys 0.056s Metrics: {"cfile_cache_hit":217,"cfile_cache_hit_bytes":8783271,"cfile_cache_miss":417,"cfile_cache_miss_bytes":20094066,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":748,"lbm_read_time_us":12709,"lbm_reads_lt_1ms":449,"lbm_write_time_us":31660,"lbm_writes_lt_1ms":643,"mutex_wait_us":85,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":13312,"thread_start_us":80,"threads_started":1,"update_count":3000}
I20260812 06:20:30.425817 13552 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:30.426200 13552 tablet_replica.cc:333] T 984a27d312f04e1d97a10e5e26552d1a P bfe5919082ef460a978e3aebd8bd6f76: stopping tablet replica
I20260812 06:20:30.426378 13552 raft_consensus.cc:2243] T 984a27d312f04e1d97a10e5e26552d1a P bfe5919082ef460a978e3aebd8bd6f76 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:30.426589 13552 raft_consensus.cc:2272] T 984a27d312f04e1d97a10e5e26552d1a P bfe5919082ef460a978e3aebd8bd6f76 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:30.442332 13552 tablet_server.cc:196] TabletServer@127.13.60.1:0 shutdown complete.
I20260812 06:20:30.478890 13552 master.cc:562] Master@127.13.60.62:40879 shutting down...
I20260812 06:20:30.484012 13552 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 04298685eaa44694925f6f635df5ee58 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:30.484256 13552 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 04298685eaa44694925f6f635df5ee58 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:30.484359 13552 tablet_replica.cc:333] T 00000000000000000000000000000000 P 04298685eaa44694925f6f635df5ee58: stopping tablet replica
I20260812 06:20:30.497442 13552 master.cc:584] Master@127.13.60.62:40879 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5809 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11703 ms total)

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