[==========] 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.201743 12892 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.12.151.62:42039
I20260812 06:20:18.202723 12892 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.203300 12892 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:18.209445 12902 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:18.209532 12908 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:18.209497 12892 server_base.cc:1061] running on GCE node
W20260812 06:20:18.209669 12901 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:18.210156 12892 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:18.210259 12892 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.210290 12892 hybrid_clock.cc:648] HybridClock initialized: now 1786515618210289 us; error 0 us; skew 500 ppm
I20260812 06:20:18.211946 12892 webserver.cc:533] Webserver started at http://127.12.151.62:32995/ using document root <none> and password file <none>
I20260812 06:20:18.212464 12892 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:18.212519 12892 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:18.212713 12892 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:18.214298 12892 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618190838-12892-0/minicluster-data/master-0-root/instance:
uuid: "083a7b399527483ba8fac8306d1fd923"
format_stamp: "Formatted at 2026-08-12 06:20:18 on dist-test-slave-nj21"
I20260812 06:20:18.217707 12892 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.005s	sys 0.000s
I20260812 06:20:18.219745 12924 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.220726 12892 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:20:18.220821 12892 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618190838-12892-0/minicluster-data/master-0-root
uuid: "083a7b399527483ba8fac8306d1fd923"
format_stamp: "Formatted at 2026-08-12 06:20:18 on dist-test-slave-nj21"
I20260812 06:20:18.220901 12892 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618190838-12892-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618190838-12892-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618190838-12892-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.234797 12892 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:18.235370 12892 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.235502 12892 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:18.242789 12892 rpc_server.cc:307] RPC server started. Bound to: 127.12.151.62:42039
I20260812 06:20:18.242874 13011 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.12.151.62:42039 every 8 connection(s)
I20260812 06:20:18.245131 13013 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.250957 13013 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 083a7b399527483ba8fac8306d1fd923: Bootstrap starting.
I20260812 06:20:18.253379 13013 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 083a7b399527483ba8fac8306d1fd923: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:18.254308 13013 log.cc:826] T 00000000000000000000000000000000 P 083a7b399527483ba8fac8306d1fd923: Log is configured to *not* fsync() on all Append() calls
I20260812 06:20:18.256035 13013 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 083a7b399527483ba8fac8306d1fd923: No bootstrap required, opened a new log
I20260812 06:20:18.258858 13013 raft_consensus.cc:359] T 00000000000000000000000000000000 P 083a7b399527483ba8fac8306d1fd923 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "083a7b399527483ba8fac8306d1fd923" member_type: VOTER }
I20260812 06:20:18.259032 13013 raft_consensus.cc:385] T 00000000000000000000000000000000 P 083a7b399527483ba8fac8306d1fd923 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:18.259096 13013 raft_consensus.cc:740] T 00000000000000000000000000000000 P 083a7b399527483ba8fac8306d1fd923 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 083a7b399527483ba8fac8306d1fd923, State: Initialized, Role: FOLLOWER
I20260812 06:20:18.259711 13013 consensus_queue.cc:260] T 00000000000000000000000000000000 P 083a7b399527483ba8fac8306d1fd923 [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: "083a7b399527483ba8fac8306d1fd923" member_type: VOTER }
I20260812 06:20:18.259874 13013 raft_consensus.cc:399] T 00000000000000000000000000000000 P 083a7b399527483ba8fac8306d1fd923 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:18.259948 13013 raft_consensus.cc:493] T 00000000000000000000000000000000 P 083a7b399527483ba8fac8306d1fd923 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:18.260102 13013 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 083a7b399527483ba8fac8306d1fd923 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:18.260905 13013 raft_consensus.cc:515] T 00000000000000000000000000000000 P 083a7b399527483ba8fac8306d1fd923 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "083a7b399527483ba8fac8306d1fd923" member_type: VOTER }
I20260812 06:20:18.261340 13013 leader_election.cc:304] T 00000000000000000000000000000000 P 083a7b399527483ba8fac8306d1fd923 [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: 083a7b399527483ba8fac8306d1fd923; no voters: 
I20260812 06:20:18.261677 13013 leader_election.cc:290] T 00000000000000000000000000000000 P 083a7b399527483ba8fac8306d1fd923 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:18.261778 13016 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 083a7b399527483ba8fac8306d1fd923 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:18.262009 13016 raft_consensus.cc:697] T 00000000000000000000000000000000 P 083a7b399527483ba8fac8306d1fd923 [term 1 LEADER]: Becoming Leader. State: Replica: 083a7b399527483ba8fac8306d1fd923, State: Running, Role: LEADER
I20260812 06:20:18.262429 13016 consensus_queue.cc:237] T 00000000000000000000000000000000 P 083a7b399527483ba8fac8306d1fd923 [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: "083a7b399527483ba8fac8306d1fd923" member_type: VOTER }
I20260812 06:20:18.262701 13013 sys_catalog.cc:565] T 00000000000000000000000000000000 P 083a7b399527483ba8fac8306d1fd923 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:18.264099 13019 sys_catalog.cc:455] T 00000000000000000000000000000000 P 083a7b399527483ba8fac8306d1fd923 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 083a7b399527483ba8fac8306d1fd923. Latest consensus state: current_term: 1 leader_uuid: "083a7b399527483ba8fac8306d1fd923" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "083a7b399527483ba8fac8306d1fd923" member_type: VOTER } }
I20260812 06:20:18.264223 13019 sys_catalog.cc:458] T 00000000000000000000000000000000 P 083a7b399527483ba8fac8306d1fd923 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:18.264479 13017 sys_catalog.cc:455] T 00000000000000000000000000000000 P 083a7b399527483ba8fac8306d1fd923 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "083a7b399527483ba8fac8306d1fd923" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "083a7b399527483ba8fac8306d1fd923" member_type: VOTER } }
I20260812 06:20:18.264559 13017 sys_catalog.cc:458] T 00000000000000000000000000000000 P 083a7b399527483ba8fac8306d1fd923 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:18.264628 13029 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:18.264972 12892 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:18.266961 13029 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:18.271250 13029 catalog_manager.cc:1383] Generated new cluster ID: b76eba69e0a64bd79c1b9a7165fe8d44
I20260812 06:20:18.271317 13029 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:18.279383 13029 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:18.280186 13029 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:18.292635 13029 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 083a7b399527483ba8fac8306d1fd923: Generated new TSK 0
I20260812 06:20:18.293259 13029 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:18.297879 12892 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:18.300757 13041 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.300778 13043 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:18.300836 13045 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:18.301000 12892 server_base.cc:1061] running on GCE node
I20260812 06:20:18.301174 12892 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:18.301218 12892 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.301239 12892 hybrid_clock.cc:648] HybridClock initialized: now 1786515618301238 us; error 0 us; skew 500 ppm
I20260812 06:20:18.302120 12892 webserver.cc:533] Webserver started at http://127.12.151.1:38731/ using document root <none> and password file <none>
I20260812 06:20:18.302280 12892 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:18.302333 12892 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:18.302409 12892 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:18.302815 12892 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618190838-12892-0/minicluster-data/ts-0-root/instance:
uuid: "ae58ba453bf64e90a85c558c6069e15a"
format_stamp: "Formatted at 2026-08-12 06:20:18 on dist-test-slave-nj21"
I20260812 06:20:18.304631 12892 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:20:18.305732 13052 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.305981 12892 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:20:18.306044 12892 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618190838-12892-0/minicluster-data/ts-0-root
uuid: "ae58ba453bf64e90a85c558c6069e15a"
format_stamp: "Formatted at 2026-08-12 06:20:18 on dist-test-slave-nj21"
I20260812 06:20:18.306113 12892 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618190838-12892-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618190838-12892-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618190838-12892-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:18.313525 12892 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:18.313925 12892 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:18.314668 12892 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:18.315526 12892 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:18.315578 12892 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:18.315625 12892 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:18.315655 12892 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:18.321218 12892 rpc_server.cc:307] RPC server started. Bound to: 127.12.151.1:45043
I20260812 06:20:18.321277 13167 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.12.151.1:45043 every 8 connection(s)
I20260812 06:20:18.344873 13168 heartbeater.cc:344] Connected to a master server at 127.12.151.62:42039
I20260812 06:20:18.345160 13168 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:18.345688 13168 heartbeater.cc:507] Master 127.12.151.62:42039 requested a full tablet report, sending...
I20260812 06:20:18.347285 12952 ts_manager.cc:194] Registered new tserver with Master: ae58ba453bf64e90a85c558c6069e15a (127.12.151.1:45043)
I20260812 06:20:18.348081 12892 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.026276067s
I20260812 06:20:18.348868 12952 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:46062
I20260812 06:20:18.357692 12952 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:46072:
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:18.372056 13108 tablet_service.cc:1511] Processing CreateTablet for tablet 55428838d95c4daa9e566c71f38e65cf (DEFAULT_TABLE table=heavy-update-compaction-test [id=17bae8d6788a467b8f27bf3ddd1830da]), partition=
I20260812 06:20:18.372516 13108 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 55428838d95c4daa9e566c71f38e65cf. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:18.375157 13182 tablet_bootstrap.cc:492] T 55428838d95c4daa9e566c71f38e65cf P ae58ba453bf64e90a85c558c6069e15a: Bootstrap starting.
I20260812 06:20:18.376184 13182 tablet_bootstrap.cc:654] T 55428838d95c4daa9e566c71f38e65cf P ae58ba453bf64e90a85c558c6069e15a: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:18.377292 13182 tablet_bootstrap.cc:492] T 55428838d95c4daa9e566c71f38e65cf P ae58ba453bf64e90a85c558c6069e15a: No bootstrap required, opened a new log
I20260812 06:20:18.377379 13182 ts_tablet_manager.cc:1403] T 55428838d95c4daa9e566c71f38e65cf P ae58ba453bf64e90a85c558c6069e15a: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:20:18.377790 13182 raft_consensus.cc:359] T 55428838d95c4daa9e566c71f38e65cf P ae58ba453bf64e90a85c558c6069e15a [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ae58ba453bf64e90a85c558c6069e15a" member_type: VOTER last_known_addr { host: "127.12.151.1" port: 45043 } }
I20260812 06:20:18.377893 13182 raft_consensus.cc:385] T 55428838d95c4daa9e566c71f38e65cf P ae58ba453bf64e90a85c558c6069e15a [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:18.377914 13182 raft_consensus.cc:740] T 55428838d95c4daa9e566c71f38e65cf P ae58ba453bf64e90a85c558c6069e15a [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: ae58ba453bf64e90a85c558c6069e15a, State: Initialized, Role: FOLLOWER
I20260812 06:20:18.378036 13182 consensus_queue.cc:260] T 55428838d95c4daa9e566c71f38e65cf P ae58ba453bf64e90a85c558c6069e15a [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: "ae58ba453bf64e90a85c558c6069e15a" member_type: VOTER last_known_addr { host: "127.12.151.1" port: 45043 } }
I20260812 06:20:18.378104 13182 raft_consensus.cc:399] T 55428838d95c4daa9e566c71f38e65cf P ae58ba453bf64e90a85c558c6069e15a [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:18.378140 13182 raft_consensus.cc:493] T 55428838d95c4daa9e566c71f38e65cf P ae58ba453bf64e90a85c558c6069e15a [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:18.378187 13182 raft_consensus.cc:3060] T 55428838d95c4daa9e566c71f38e65cf P ae58ba453bf64e90a85c558c6069e15a [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:18.379163 13182 raft_consensus.cc:515] T 55428838d95c4daa9e566c71f38e65cf P ae58ba453bf64e90a85c558c6069e15a [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ae58ba453bf64e90a85c558c6069e15a" member_type: VOTER last_known_addr { host: "127.12.151.1" port: 45043 } }
I20260812 06:20:18.379299 13182 leader_election.cc:304] T 55428838d95c4daa9e566c71f38e65cf P ae58ba453bf64e90a85c558c6069e15a [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: ae58ba453bf64e90a85c558c6069e15a; no voters: 
I20260812 06:20:18.379503 13182 leader_election.cc:290] T 55428838d95c4daa9e566c71f38e65cf P ae58ba453bf64e90a85c558c6069e15a [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:18.379611 13188 raft_consensus.cc:2804] T 55428838d95c4daa9e566c71f38e65cf P ae58ba453bf64e90a85c558c6069e15a [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:18.379876 13188 raft_consensus.cc:697] T 55428838d95c4daa9e566c71f38e65cf P ae58ba453bf64e90a85c558c6069e15a [term 1 LEADER]: Becoming Leader. State: Replica: ae58ba453bf64e90a85c558c6069e15a, State: Running, Role: LEADER
I20260812 06:20:18.379971 13182 ts_tablet_manager.cc:1434] T 55428838d95c4daa9e566c71f38e65cf P ae58ba453bf64e90a85c558c6069e15a: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:20:18.380088 13188 consensus_queue.cc:237] T 55428838d95c4daa9e566c71f38e65cf P ae58ba453bf64e90a85c558c6069e15a [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: "ae58ba453bf64e90a85c558c6069e15a" member_type: VOTER last_known_addr { host: "127.12.151.1" port: 45043 } }
I20260812 06:20:18.380432 13168 heartbeater.cc:499] Master 127.12.151.62:42039 was elected leader, sending a full tablet report...
I20260812 06:20:18.382642 12952 catalog_manager.cc:5719] T 55428838d95c4daa9e566c71f38e65cf P ae58ba453bf64e90a85c558c6069e15a reported cstate change: term changed from 0 to 1, leader changed from <none> to ae58ba453bf64e90a85c558c6069e15a (127.12.151.1). New cstate: current_term: 1 leader_uuid: "ae58ba453bf64e90a85c558c6069e15a" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ae58ba453bf64e90a85c558c6069e15a" member_type: VOTER last_known_addr { host: "127.12.151.1" port: 45043 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:18.447327 12892 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.055s	user 0.022s	sys 0.004s
I20260812 06:20:18.572264 13170 maintenance_manager.cc:419] P ae58ba453bf64e90a85c558c6069e15a: Scheduling FlushMRSOp(55428838d95c4daa9e566c71f38e65cf): perf score=19.054940
I20260812 06:20:18.717494 13060 maintenance_manager.cc:643] P ae58ba453bf64e90a85c558c6069e15a: FlushMRSOp(55428838d95c4daa9e566c71f38e65cf) complete. Timing: real 0.145s	user 0.123s	sys 0.016s Metrics: {"bytes_written":8697369,"cfile_init":1,"compiler_manager_pool.queue_time_us":194,"delete_count":0,"dirs.queue_time_us":212,"dirs.run_cpu_time_us":146,"dirs.run_wall_time_us":930,"drs_written":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4,"lbm_write_time_us":33986,"lbm_writes_lt_1ms":669,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":296832,"thread_start_us":103,"threads_started":1,"update_count":1060}
I20260812 06:20:18.719041 13170 maintenance_manager.cc:419] P ae58ba453bf64e90a85c558c6069e15a: Scheduling LogGCOp(55428838d95c4daa9e566c71f38e65cf): free 20743880 bytes of WAL
I20260812 06:20:18.719367 13060 log_reader.cc:385] T 55428838d95c4daa9e566c71f38e65cf: removed 2 log segments from log reader
I20260812 06:20:18.719444 13060 log.cc:1079] T 55428838d95c4daa9e566c71f38e65cf P ae58ba453bf64e90a85c558c6069e15a: Deleting log segment in path: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618190838-12892-0/minicluster-data/ts-0-root/wals/55428838d95c4daa9e566c71f38e65cf/wal-000000001 (ops 1-6)
I20260812 06:20:18.719496 13060 log.cc:1079] T 55428838d95c4daa9e566c71f38e65cf P ae58ba453bf64e90a85c558c6069e15a: Deleting log segment in path: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618190838-12892-0/minicluster-data/ts-0-root/wals/55428838d95c4daa9e566c71f38e65cf/wal-000000002 (ops 7-11)
I20260812 06:20:18.724362 13060 maintenance_manager.cc:643] P ae58ba453bf64e90a85c558c6069e15a: LogGCOp(55428838d95c4daa9e566c71f38e65cf) complete. Timing: real 0.005s	user 0.000s	sys 0.004s Metrics: {}
I20260812 06:20:18.724900 13170 maintenance_manager.cc:419] P ae58ba453bf64e90a85c558c6069e15a: Scheduling UndoDeltaBlockGCOp(55428838d95c4daa9e566c71f38e65cf): 16411396 bytes on disk
I20260812 06:20:18.725579 13060 maintenance_manager.cc:643] P ae58ba453bf64e90a85c558c6069e15a: UndoDeltaBlockGCOp(55428838d95c4daa9e566c71f38e65cf) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":77,"lbm_reads_lt_1ms":4}
I20260812 06:20:18.726073 13170 maintenance_manager.cc:419] P ae58ba453bf64e90a85c558c6069e15a: Scheduling FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf): perf score=2.188937
I20260812 06:20:18.747218 13060 maintenance_manager.cc:643] P ae58ba453bf64e90a85c558c6069e15a: FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf) complete. Timing: real 0.021s	user 0.002s	sys 0.009s Metrics: {"bytes_written":3610355,"delete_count":0,"lbm_write_time_us":4757,"lbm_writes_lt_1ms":91,"reinsert_count":0,"update_count":440}
I20260812 06:20:18.747792 13170 maintenance_manager.cc:419] P ae58ba453bf64e90a85c558c6069e15a: Scheduling FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf): perf score=2.188937
I20260812 06:20:18.760574 13060 maintenance_manager.cc:643] P ae58ba453bf64e90a85c558c6069e15a: FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf) complete. Timing: real 0.013s	user 0.010s	sys 0.002s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4768,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:18.761035 13170 maintenance_manager.cc:419] P ae58ba453bf64e90a85c558c6069e15a: Scheduling MajorDeltaCompactionOp(55428838d95c4daa9e566c71f38e65cf): perf score=1.000000
I20260812 06:20:18.885996 13060 maintenance_manager.cc:643] P ae58ba453bf64e90a85c558c6069e15a: MajorDeltaCompactionOp(55428838d95c4daa9e566c71f38e65cf) complete. Timing: real 0.125s	user 0.092s	sys 0.029s Metrics: {"cfile_cache_miss":433,"cfile_cache_miss_bytes":20672383,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":776,"lbm_read_time_us":7263,"lbm_reads_lt_1ms":469,"lbm_write_time_us":20958,"lbm_writes_lt_1ms":443,"mutex_wait_us":55,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1280,"thread_start_us":277,"threads_started":5,"update_count":2000}
I20260812 06:20:18.886523 13170 maintenance_manager.cc:419] P ae58ba453bf64e90a85c558c6069e15a: Scheduling FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf): perf score=10.126437
I20260812 06:20:18.926685 13060 maintenance_manager.cc:643] P ae58ba453bf64e90a85c558c6069e15a: FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf) complete. Timing: real 0.040s	user 0.012s	sys 0.020s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16456,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:20:18.927166 13170 maintenance_manager.cc:419] P ae58ba453bf64e90a85c558c6069e15a: Scheduling FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf): perf score=2.188937
I20260812 06:20:18.937078 13060 maintenance_manager.cc:643] P ae58ba453bf64e90a85c558c6069e15a: FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3654,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:18.937669 13170 maintenance_manager.cc:419] P ae58ba453bf64e90a85c558c6069e15a: Scheduling MajorDeltaCompactionOp(55428838d95c4daa9e566c71f38e65cf): perf score=1.000000
I20260812 06:20:19.053629 13060 maintenance_manager.cc:643] P ae58ba453bf64e90a85c558c6069e15a: MajorDeltaCompactionOp(55428838d95c4daa9e566c71f38e65cf) complete. Timing: real 0.116s	user 0.083s	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":902,"lbm_read_time_us":7805,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22812,"lbm_writes_lt_1ms":443,"mutex_wait_us":295,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11520,"update_count":2000}
I20260812 06:20:19.054097 13170 maintenance_manager.cc:419] P ae58ba453bf64e90a85c558c6069e15a: Scheduling FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf): perf score=10.126437
I20260812 06:20:19.090765 13060 maintenance_manager.cc:643] P ae58ba453bf64e90a85c558c6069e15a: FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf) complete. Timing: real 0.037s	user 0.024s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14494,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:20:19.091320 13170 maintenance_manager.cc:419] P ae58ba453bf64e90a85c558c6069e15a: Scheduling FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf): perf score=2.188937
I20260812 06:20:19.101001 13060 maintenance_manager.cc:643] P ae58ba453bf64e90a85c558c6069e15a: FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3541,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:19.101823 13170 maintenance_manager.cc:419] P ae58ba453bf64e90a85c558c6069e15a: Scheduling MajorDeltaCompactionOp(55428838d95c4daa9e566c71f38e65cf): perf score=1.000000
I20260812 06:20:19.218663 13060 maintenance_manager.cc:643] P ae58ba453bf64e90a85c558c6069e15a: MajorDeltaCompactionOp(55428838d95c4daa9e566c71f38e65cf) complete. Timing: real 0.117s	user 0.105s	sys 0.012s 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":1072,"lbm_read_time_us":7401,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22927,"lbm_writes_lt_1ms":443,"mutex_wait_us":300,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2000}
I20260812 06:20:19.219274 13170 maintenance_manager.cc:419] P ae58ba453bf64e90a85c558c6069e15a: Scheduling FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf): perf score=10.126437
I20260812 06:20:19.261603 13060 maintenance_manager.cc:643] P ae58ba453bf64e90a85c558c6069e15a: FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf) complete. Timing: real 0.042s	user 0.019s	sys 0.018s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13400,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:19.262174 13170 maintenance_manager.cc:419] P ae58ba453bf64e90a85c558c6069e15a: Scheduling FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf): perf score=2.188937
I20260812 06:20:19.277563 13060 maintenance_manager.cc:643] P ae58ba453bf64e90a85c558c6069e15a: FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf) complete. Timing: real 0.015s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5743,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:19.278080 13170 maintenance_manager.cc:419] P ae58ba453bf64e90a85c558c6069e15a: Scheduling MajorDeltaCompactionOp(55428838d95c4daa9e566c71f38e65cf): perf score=1.000000
I20260812 06:20:19.407905 13060 maintenance_manager.cc:643] P ae58ba453bf64e90a85c558c6069e15a: MajorDeltaCompactionOp(55428838d95c4daa9e566c71f38e65cf) complete. Timing: real 0.130s	user 0.090s	sys 0.039s 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":131,"lbm_read_time_us":10504,"lbm_reads_lt_1ms":472,"lbm_write_time_us":19791,"lbm_writes_lt_1ms":443,"mutex_wait_us":21,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12160,"update_count":2000}
I20260812 06:20:19.408402 13170 maintenance_manager.cc:419] P ae58ba453bf64e90a85c558c6069e15a: Scheduling FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf): perf score=10.126437
I20260812 06:20:19.455063 13060 maintenance_manager.cc:643] P ae58ba453bf64e90a85c558c6069e15a: FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf) complete. Timing: real 0.047s	user 0.013s	sys 0.020s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":15831,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:19.455605 13170 maintenance_manager.cc:419] P ae58ba453bf64e90a85c558c6069e15a: Scheduling FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf): perf score=2.188937
I20260812 06:20:19.466012 13060 maintenance_manager.cc:643] P ae58ba453bf64e90a85c558c6069e15a: FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf) complete. Timing: real 0.010s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3949,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:19.466539 13170 maintenance_manager.cc:419] P ae58ba453bf64e90a85c558c6069e15a: Scheduling MajorDeltaCompactionOp(55428838d95c4daa9e566c71f38e65cf): perf score=1.000000
I20260812 06:20:19.582231 13060 maintenance_manager.cc:643] P ae58ba453bf64e90a85c558c6069e15a: MajorDeltaCompactionOp(55428838d95c4daa9e566c71f38e65cf) complete. Timing: real 0.115s	user 0.094s	sys 0.021s 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":300,"lbm_read_time_us":7557,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22622,"lbm_writes_lt_1ms":443,"mutex_wait_us":72,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2000}
I20260812 06:20:19.582701 13170 maintenance_manager.cc:419] P ae58ba453bf64e90a85c558c6069e15a: Scheduling FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf): perf score=10.126437
I20260812 06:20:19.615533 13060 maintenance_manager.cc:643] P ae58ba453bf64e90a85c558c6069e15a: FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf) complete. Timing: real 0.033s	user 0.022s	sys 0.007s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14677,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:20:19.616427 13170 maintenance_manager.cc:419] P ae58ba453bf64e90a85c558c6069e15a: Scheduling FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf): perf score=2.188937
I20260812 06:20:19.627242 13060 maintenance_manager.cc:643] P ae58ba453bf64e90a85c558c6069e15a: FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf) complete. Timing: real 0.011s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3660,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:19.627751 13170 maintenance_manager.cc:419] P ae58ba453bf64e90a85c558c6069e15a: Scheduling MajorDeltaCompactionOp(55428838d95c4daa9e566c71f38e65cf): perf score=1.000000
I20260812 06:20:19.761266 13060 maintenance_manager.cc:643] P ae58ba453bf64e90a85c558c6069e15a: MajorDeltaCompactionOp(55428838d95c4daa9e566c71f38e65cf) complete. Timing: real 0.133s	user 0.114s	sys 0.019s 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":258,"lbm_read_time_us":8959,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26973,"lbm_writes_lt_1ms":443,"mutex_wait_us":23,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":138368,"update_count":2000}
I20260812 06:20:19.761770 13170 maintenance_manager.cc:419] P ae58ba453bf64e90a85c558c6069e15a: Scheduling FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf): perf score=10.126437
I20260812 06:20:19.805346 13060 maintenance_manager.cc:643] P ae58ba453bf64e90a85c558c6069e15a: FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf) complete. Timing: real 0.043s	user 0.017s	sys 0.024s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16863,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:20:19.805931 13170 maintenance_manager.cc:419] P ae58ba453bf64e90a85c558c6069e15a: Scheduling FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf): perf score=2.188937
I20260812 06:20:19.816188 13060 maintenance_manager.cc:643] P ae58ba453bf64e90a85c558c6069e15a: FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3861,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:19.816602 13170 maintenance_manager.cc:419] P ae58ba453bf64e90a85c558c6069e15a: Scheduling FlushMRSOp(55428838d95c4daa9e566c71f38e65cf): perf score=1.000000
I20260812 06:20:19.855561 13060 maintenance_manager.cc:643] P ae58ba453bf64e90a85c558c6069e15a: FlushMRSOp(55428838d95c4daa9e566c71f38e65cf) complete. Timing: real 0.039s	user 0.022s	sys 0.004s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":66,"dirs.run_cpu_time_us":215,"dirs.run_wall_time_us":1170,"drs_written":1,"lbm_read_time_us":43,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1372,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:20:19.856396 13170 maintenance_manager.cc:419] P ae58ba453bf64e90a85c558c6069e15a: Scheduling LogGCOp(55428838d95c4daa9e566c71f38e65cf): free 112692368 bytes of WAL
I20260812 06:20:19.856624 13060 log_reader.cc:385] T 55428838d95c4daa9e566c71f38e65cf: removed 11 log segments from log reader
I20260812 06:20:19.856669 13060 log.cc:1079] T 55428838d95c4daa9e566c71f38e65cf P ae58ba453bf64e90a85c558c6069e15a: Deleting log segment in path: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618190838-12892-0/minicluster-data/ts-0-root/wals/55428838d95c4daa9e566c71f38e65cf/wal-000000003 (ops 12-16)
I20260812 06:20:19.856696 13060 log.cc:1079] T 55428838d95c4daa9e566c71f38e65cf P ae58ba453bf64e90a85c558c6069e15a: Deleting log segment in path: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618190838-12892-0/minicluster-data/ts-0-root/wals/55428838d95c4daa9e566c71f38e65cf/wal-000000004 (ops 17-21)
I20260812 06:20:19.856729 13060 log.cc:1079] T 55428838d95c4daa9e566c71f38e65cf P ae58ba453bf64e90a85c558c6069e15a: Deleting log segment in path: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618190838-12892-0/minicluster-data/ts-0-root/wals/55428838d95c4daa9e566c71f38e65cf/wal-000000005 (ops 22-26)
I20260812 06:20:19.856760 13060 log.cc:1079] T 55428838d95c4daa9e566c71f38e65cf P ae58ba453bf64e90a85c558c6069e15a: Deleting log segment in path: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618190838-12892-0/minicluster-data/ts-0-root/wals/55428838d95c4daa9e566c71f38e65cf/wal-000000006 (ops 27-31)
I20260812 06:20:19.856791 13060 log.cc:1079] T 55428838d95c4daa9e566c71f38e65cf P ae58ba453bf64e90a85c558c6069e15a: Deleting log segment in path: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618190838-12892-0/minicluster-data/ts-0-root/wals/55428838d95c4daa9e566c71f38e65cf/wal-000000007 (ops 32-36)
I20260812 06:20:19.856824 13060 log.cc:1079] T 55428838d95c4daa9e566c71f38e65cf P ae58ba453bf64e90a85c558c6069e15a: Deleting log segment in path: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618190838-12892-0/minicluster-data/ts-0-root/wals/55428838d95c4daa9e566c71f38e65cf/wal-000000008 (ops 37-41)
I20260812 06:20:19.856856 13060 log.cc:1079] T 55428838d95c4daa9e566c71f38e65cf P ae58ba453bf64e90a85c558c6069e15a: Deleting log segment in path: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618190838-12892-0/minicluster-data/ts-0-root/wals/55428838d95c4daa9e566c71f38e65cf/wal-000000009 (ops 42-46)
I20260812 06:20:19.856889 13060 log.cc:1079] T 55428838d95c4daa9e566c71f38e65cf P ae58ba453bf64e90a85c558c6069e15a: Deleting log segment in path: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618190838-12892-0/minicluster-data/ts-0-root/wals/55428838d95c4daa9e566c71f38e65cf/wal-000000010 (ops 47-51)
I20260812 06:20:19.856921 13060 log.cc:1079] T 55428838d95c4daa9e566c71f38e65cf P ae58ba453bf64e90a85c558c6069e15a: Deleting log segment in path: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618190838-12892-0/minicluster-data/ts-0-root/wals/55428838d95c4daa9e566c71f38e65cf/wal-000000011 (ops 52-56)
I20260812 06:20:19.856951 13060 log.cc:1079] T 55428838d95c4daa9e566c71f38e65cf P ae58ba453bf64e90a85c558c6069e15a: Deleting log segment in path: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618190838-12892-0/minicluster-data/ts-0-root/wals/55428838d95c4daa9e566c71f38e65cf/wal-000000012 (ops 57-61)
I20260812 06:20:19.856983 13060 log.cc:1079] T 55428838d95c4daa9e566c71f38e65cf P ae58ba453bf64e90a85c558c6069e15a: Deleting log segment in path: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618190838-12892-0/minicluster-data/ts-0-root/wals/55428838d95c4daa9e566c71f38e65cf/wal-000000013 (ops 62-66)
I20260812 06:20:19.877125 13060 maintenance_manager.cc:643] P ae58ba453bf64e90a85c558c6069e15a: LogGCOp(55428838d95c4daa9e566c71f38e65cf) complete. Timing: real 0.021s	user 0.000s	sys 0.019s Metrics: {}
I20260812 06:20:19.877563 13170 maintenance_manager.cc:419] P ae58ba453bf64e90a85c558c6069e15a: Scheduling UndoDeltaBlockGCOp(55428838d95c4daa9e566c71f38e65cf): 447 bytes on disk
I20260812 06:20:19.878041 13060 maintenance_manager.cc:643] P ae58ba453bf64e90a85c558c6069e15a: UndoDeltaBlockGCOp(55428838d95c4daa9e566c71f38e65cf) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":64,"lbm_reads_lt_1ms":4}
I20260812 06:20:19.878571 13170 maintenance_manager.cc:419] P ae58ba453bf64e90a85c558c6069e15a: Scheduling FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf): perf score=3.181125
I20260812 06:20:19.901453 13060 maintenance_manager.cc:643] P ae58ba453bf64e90a85c558c6069e15a: FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf) complete. Timing: real 0.023s	user 0.003s	sys 0.012s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":6116,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:19.901930 13170 maintenance_manager.cc:419] P ae58ba453bf64e90a85c558c6069e15a: Scheduling FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf): perf score=2.188937
I20260812 06:20:19.911027 13060 maintenance_manager.cc:643] P ae58ba453bf64e90a85c558c6069e15a: FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf) complete. Timing: real 0.009s	user 0.002s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3267,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:19.911554 13170 maintenance_manager.cc:419] P ae58ba453bf64e90a85c558c6069e15a: Scheduling MajorDeltaCompactionOp(55428838d95c4daa9e566c71f38e65cf): perf score=1.000000
I20260812 06:20:20.105624 13060 maintenance_manager.cc:643] P ae58ba453bf64e90a85c558c6069e15a: MajorDeltaCompactionOp(55428838d95c4daa9e566c71f38e65cf) complete. Timing: real 0.194s	user 0.131s	sys 0.057s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877326,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":162,"lbm_read_time_us":13740,"lbm_reads_lt_1ms":674,"lbm_write_time_us":31680,"lbm_writes_lt_1ms":643,"mutex_wait_us":46,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":9088,"thread_start_us":74,"threads_started":1,"update_count":3000}
I20260812 06:20:20.106127 13170 maintenance_manager.cc:419] P ae58ba453bf64e90a85c558c6069e15a: Scheduling FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf): perf score=14.095187
I20260812 06:20:20.152076 13060 maintenance_manager.cc:643] P ae58ba453bf64e90a85c558c6069e15a: FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf) complete. Timing: real 0.046s	user 0.030s	sys 0.015s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19962,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:20:20.152567 13170 maintenance_manager.cc:419] P ae58ba453bf64e90a85c558c6069e15a: Scheduling MajorDeltaCompactionOp(55428838d95c4daa9e566c71f38e65cf): perf score=1.000000
I20260812 06:20:20.305076 13060 maintenance_manager.cc:643] P ae58ba453bf64e90a85c558c6069e15a: MajorDeltaCompactionOp(55428838d95c4daa9e566c71f38e65cf) complete. Timing: real 0.152s	user 0.098s	sys 0.048s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672157,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":615,"lbm_read_time_us":8827,"lbm_reads_lt_1ms":463,"lbm_write_time_us":27302,"lbm_writes_lt_1ms":443,"mutex_wait_us":301,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:20:20.305544 13170 maintenance_manager.cc:419] P ae58ba453bf64e90a85c558c6069e15a: Scheduling FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf): perf score=14.095187
I20260812 06:20:20.365190 13060 maintenance_manager.cc:643] P ae58ba453bf64e90a85c558c6069e15a: FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf) complete. Timing: real 0.059s	user 0.030s	sys 0.015s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":35102,"lbm_writes_1-10_ms":1,"lbm_writes_10-100_ms":1,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:20:20.365680 13170 maintenance_manager.cc:419] P ae58ba453bf64e90a85c558c6069e15a: Scheduling FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf): perf score=2.188937
I20260812 06:20:20.392156 13060 maintenance_manager.cc:643] P ae58ba453bf64e90a85c558c6069e15a: FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf) complete. Timing: real 0.026s	user 0.017s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5266,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:20.392619 13170 maintenance_manager.cc:419] P ae58ba453bf64e90a85c558c6069e15a: Scheduling FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf): perf score=2.188937
I20260812 06:20:20.402980 13060 maintenance_manager.cc:643] P ae58ba453bf64e90a85c558c6069e15a: FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf) complete. Timing: real 0.010s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102660,"delete_count":0,"lbm_write_time_us":3909,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:20.403432 13170 maintenance_manager.cc:419] P ae58ba453bf64e90a85c558c6069e15a: Scheduling MajorDeltaCompactionOp(55428838d95c4daa9e566c71f38e65cf): perf score=1.000000
I20260812 06:20:20.596608 13060 maintenance_manager.cc:643] P ae58ba453bf64e90a85c558c6069e15a: MajorDeltaCompactionOp(55428838d95c4daa9e566c71f38e65cf) complete. Timing: real 0.193s	user 0.121s	sys 0.063s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877220,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":473,"lbm_read_time_us":13466,"lbm_reads_lt_1ms":673,"lbm_write_time_us":31858,"lbm_writes_lt_1ms":643,"mutex_wait_us":265,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":13952,"update_count":3000}
I20260812 06:20:20.597101 13170 maintenance_manager.cc:419] P ae58ba453bf64e90a85c558c6069e15a: Scheduling FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf): perf score=14.095187
I20260812 06:20:20.650746 13060 maintenance_manager.cc:643] P ae58ba453bf64e90a85c558c6069e15a: FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf) complete. Timing: real 0.053s	user 0.025s	sys 0.025s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":21275,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:20:20.651310 13170 maintenance_manager.cc:419] P ae58ba453bf64e90a85c558c6069e15a: Scheduling FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf): perf score=2.188937
I20260812 06:20:20.661724 13060 maintenance_manager.cc:643] P ae58ba453bf64e90a85c558c6069e15a: FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf) complete. Timing: real 0.010s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3888,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:20.662303 13170 maintenance_manager.cc:419] P ae58ba453bf64e90a85c558c6069e15a: Scheduling MajorDeltaCompactionOp(55428838d95c4daa9e566c71f38e65cf): perf score=1.000000
I20260812 06:20:20.829639 13060 maintenance_manager.cc:643] P ae58ba453bf64e90a85c558c6069e15a: MajorDeltaCompactionOp(55428838d95c4daa9e566c71f38e65cf) complete. Timing: real 0.167s	user 0.128s	sys 0.035s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774691,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":320,"lbm_read_time_us":12273,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25555,"lbm_writes_lt_1ms":543,"mutex_wait_us":84,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:20:20.830204 13170 maintenance_manager.cc:419] P ae58ba453bf64e90a85c558c6069e15a: Scheduling FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf): perf score=11.118625
I20260812 06:20:20.858654 13060 maintenance_manager.cc:643] P ae58ba453bf64e90a85c558c6069e15a: FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf) complete. Timing: real 0.028s	user 0.024s	sys 0.002s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":11489,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:20.859303 13170 maintenance_manager.cc:419] P ae58ba453bf64e90a85c558c6069e15a: Scheduling FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf): perf score=2.188937
I20260812 06:20:20.874181 13060 maintenance_manager.cc:643] P ae58ba453bf64e90a85c558c6069e15a: FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf) complete. Timing: real 0.015s	user 0.009s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5081,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:20.874881 13170 maintenance_manager.cc:419] P ae58ba453bf64e90a85c558c6069e15a: Scheduling MajorDeltaCompactionOp(55428838d95c4daa9e566c71f38e65cf): perf score=1.000000
I20260812 06:20:21.022799 13060 maintenance_manager.cc:643] P ae58ba453bf64e90a85c558c6069e15a: MajorDeltaCompactionOp(55428838d95c4daa9e566c71f38e65cf) complete. Timing: real 0.148s	user 0.089s	sys 0.051s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1056,"lbm_read_time_us":8295,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23332,"lbm_writes_lt_1ms":443,"mutex_wait_us":276,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12416,"update_count":2000}
I20260812 06:20:21.023272 13170 maintenance_manager.cc:419] P ae58ba453bf64e90a85c558c6069e15a: Scheduling FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf): perf score=10.126437
I20260812 06:20:21.054566 13060 maintenance_manager.cc:643] P ae58ba453bf64e90a85c558c6069e15a: FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf) complete. Timing: real 0.031s	user 0.017s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":12992,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:21.055181 13170 maintenance_manager.cc:419] P ae58ba453bf64e90a85c558c6069e15a: Scheduling FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf): perf score=2.188937
I20260812 06:20:21.070525 13060 maintenance_manager.cc:643] P ae58ba453bf64e90a85c558c6069e15a: FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf) complete. Timing: real 0.015s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5814,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:21.071007 13170 maintenance_manager.cc:419] P ae58ba453bf64e90a85c558c6069e15a: Scheduling MajorDeltaCompactionOp(55428838d95c4daa9e566c71f38e65cf): perf score=1.000000
I20260812 06:20:21.180943 13060 maintenance_manager.cc:643] P ae58ba453bf64e90a85c558c6069e15a: MajorDeltaCompactionOp(55428838d95c4daa9e566c71f38e65cf) complete. Timing: real 0.110s	user 0.099s	sys 0.009s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":212,"lbm_read_time_us":7349,"lbm_reads_lt_1ms":464,"lbm_write_time_us":19618,"lbm_writes_lt_1ms":443,"mutex_wait_us":37,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":17536,"update_count":2000}
I20260812 06:20:21.181548 13170 maintenance_manager.cc:419] P ae58ba453bf64e90a85c558c6069e15a: Scheduling FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf): perf score=10.126437
I20260812 06:20:21.216406 13060 maintenance_manager.cc:643] P ae58ba453bf64e90a85c558c6069e15a: FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf) complete. Timing: real 0.035s	user 0.017s	sys 0.013s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13152,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:21.216890 13170 maintenance_manager.cc:419] P ae58ba453bf64e90a85c558c6069e15a: Scheduling FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf): perf score=2.188937
I20260812 06:20:21.226881 13060 maintenance_manager.cc:643] P ae58ba453bf64e90a85c558c6069e15a: FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3674,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:21.227360 13170 maintenance_manager.cc:419] P ae58ba453bf64e90a85c558c6069e15a: Scheduling FlushMRSOp(55428838d95c4daa9e566c71f38e65cf): perf score=1.000000
I20260812 06:20:21.254669 13060 maintenance_manager.cc:643] P ae58ba453bf64e90a85c558c6069e15a: FlushMRSOp(55428838d95c4daa9e566c71f38e65cf) complete. Timing: real 0.027s	user 0.026s	sys 0.000s Metrics: {"bytes_written":1193509,"cfile_init":1,"dirs.queue_time_us":72,"dirs.run_cpu_time_us":227,"dirs.run_wall_time_us":1139,"drs_written":1,"lbm_read_time_us":42,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1443,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:20:21.255388 13170 maintenance_manager.cc:419] P ae58ba453bf64e90a85c558c6069e15a: Scheduling LogGCOp(55428838d95c4daa9e566c71f38e65cf): free 120553380 bytes of WAL
I20260812 06:20:21.255609 13060 log_reader.cc:385] T 55428838d95c4daa9e566c71f38e65cf: removed 12 log segments from log reader
I20260812 06:20:21.255654 13060 log.cc:1079] T 55428838d95c4daa9e566c71f38e65cf P ae58ba453bf64e90a85c558c6069e15a: Deleting log segment in path: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618190838-12892-0/minicluster-data/ts-0-root/wals/55428838d95c4daa9e566c71f38e65cf/wal-000000014 (ops 67-71)
I20260812 06:20:21.255717 13060 log.cc:1079] T 55428838d95c4daa9e566c71f38e65cf P ae58ba453bf64e90a85c558c6069e15a: Deleting log segment in path: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618190838-12892-0/minicluster-data/ts-0-root/wals/55428838d95c4daa9e566c71f38e65cf/wal-000000015 (ops 72-76)
I20260812 06:20:21.255750 13060 log.cc:1079] T 55428838d95c4daa9e566c71f38e65cf P ae58ba453bf64e90a85c558c6069e15a: Deleting log segment in path: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618190838-12892-0/minicluster-data/ts-0-root/wals/55428838d95c4daa9e566c71f38e65cf/wal-000000016 (ops 77-81)
I20260812 06:20:21.255769 13060 log.cc:1079] T 55428838d95c4daa9e566c71f38e65cf P ae58ba453bf64e90a85c558c6069e15a: Deleting log segment in path: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618190838-12892-0/minicluster-data/ts-0-root/wals/55428838d95c4daa9e566c71f38e65cf/wal-000000017 (ops 82-86)
I20260812 06:20:21.255800 13060 log.cc:1079] T 55428838d95c4daa9e566c71f38e65cf P ae58ba453bf64e90a85c558c6069e15a: Deleting log segment in path: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618190838-12892-0/minicluster-data/ts-0-root/wals/55428838d95c4daa9e566c71f38e65cf/wal-000000018 (ops 87-90)
I20260812 06:20:21.255824 13060 log.cc:1079] T 55428838d95c4daa9e566c71f38e65cf P ae58ba453bf64e90a85c558c6069e15a: Deleting log segment in path: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618190838-12892-0/minicluster-data/ts-0-root/wals/55428838d95c4daa9e566c71f38e65cf/wal-000000019 (ops 91-95)
I20260812 06:20:21.255857 13060 log.cc:1079] T 55428838d95c4daa9e566c71f38e65cf P ae58ba453bf64e90a85c558c6069e15a: Deleting log segment in path: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618190838-12892-0/minicluster-data/ts-0-root/wals/55428838d95c4daa9e566c71f38e65cf/wal-000000020 (ops 96-100)
I20260812 06:20:21.255882 13060 log.cc:1079] T 55428838d95c4daa9e566c71f38e65cf P ae58ba453bf64e90a85c558c6069e15a: Deleting log segment in path: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618190838-12892-0/minicluster-data/ts-0-root/wals/55428838d95c4daa9e566c71f38e65cf/wal-000000021 (ops 101-104)
I20260812 06:20:21.255911 13060 log.cc:1079] T 55428838d95c4daa9e566c71f38e65cf P ae58ba453bf64e90a85c558c6069e15a: Deleting log segment in path: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618190838-12892-0/minicluster-data/ts-0-root/wals/55428838d95c4daa9e566c71f38e65cf/wal-000000022 (ops 105-109)
I20260812 06:20:21.255942 13060 log.cc:1079] T 55428838d95c4daa9e566c71f38e65cf P ae58ba453bf64e90a85c558c6069e15a: Deleting log segment in path: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618190838-12892-0/minicluster-data/ts-0-root/wals/55428838d95c4daa9e566c71f38e65cf/wal-000000023 (ops 110-114)
I20260812 06:20:21.255975 13060 log.cc:1079] T 55428838d95c4daa9e566c71f38e65cf P ae58ba453bf64e90a85c558c6069e15a: Deleting log segment in path: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618190838-12892-0/minicluster-data/ts-0-root/wals/55428838d95c4daa9e566c71f38e65cf/wal-000000024 (ops 115-119)
I20260812 06:20:21.256006 13060 log.cc:1079] T 55428838d95c4daa9e566c71f38e65cf P ae58ba453bf64e90a85c558c6069e15a: Deleting log segment in path: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618190838-12892-0/minicluster-data/ts-0-root/wals/55428838d95c4daa9e566c71f38e65cf/wal-000000025 (ops 120-124)
I20260812 06:20:21.276909 13060 maintenance_manager.cc:643] P ae58ba453bf64e90a85c558c6069e15a: LogGCOp(55428838d95c4daa9e566c71f38e65cf) complete. Timing: real 0.021s	user 0.002s	sys 0.019s Metrics: {}
I20260812 06:20:21.277300 13170 maintenance_manager.cc:419] P ae58ba453bf64e90a85c558c6069e15a: Scheduling UndoDeltaBlockGCOp(55428838d95c4daa9e566c71f38e65cf): 462 bytes on disk
I20260812 06:20:21.277719 13060 maintenance_manager.cc:643] P ae58ba453bf64e90a85c558c6069e15a: UndoDeltaBlockGCOp(55428838d95c4daa9e566c71f38e65cf) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4}
I20260812 06:20:21.278280 13170 maintenance_manager.cc:419] P ae58ba453bf64e90a85c558c6069e15a: Scheduling FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf): perf score=3.181125
I20260812 06:20:21.292754 13060 maintenance_manager.cc:643] P ae58ba453bf64e90a85c558c6069e15a: FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf) complete. Timing: real 0.014s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4512899,"delete_count":0,"lbm_write_time_us":4064,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:21.293154 13170 maintenance_manager.cc:419] P ae58ba453bf64e90a85c558c6069e15a: Scheduling FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf): perf score=2.188937
I20260812 06:20:21.306650 13060 maintenance_manager.cc:643] P ae58ba453bf64e90a85c558c6069e15a: FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf) complete. Timing: real 0.013s	user 0.010s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4660,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:21.307199 13170 maintenance_manager.cc:419] P ae58ba453bf64e90a85c558c6069e15a: Scheduling MajorDeltaCompactionOp(55428838d95c4daa9e566c71f38e65cf): perf score=1.000000
I20260812 06:20:21.467077 13060 maintenance_manager.cc:643] P ae58ba453bf64e90a85c558c6069e15a: MajorDeltaCompactionOp(55428838d95c4daa9e566c71f38e65cf) complete. Timing: real 0.160s	user 0.126s	sys 0.032s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877325,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":2154,"lbm_read_time_us":12044,"lbm_reads_lt_1ms":674,"lbm_write_time_us":30719,"lbm_writes_lt_1ms":643,"mutex_wait_us":1860,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1792,"thread_start_us":75,"threads_started":1,"update_count":3000}
I20260812 06:20:21.467607 13170 maintenance_manager.cc:419] P ae58ba453bf64e90a85c558c6069e15a: Scheduling FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf): perf score=14.095187
I20260812 06:20:21.520175 13060 maintenance_manager.cc:643] P ae58ba453bf64e90a85c558c6069e15a: FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf) complete. Timing: real 0.052s	user 0.036s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22747,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:21.520696 13170 maintenance_manager.cc:419] P ae58ba453bf64e90a85c558c6069e15a: Scheduling FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf): perf score=2.188937
I20260812 06:20:21.536120 13060 maintenance_manager.cc:643] P ae58ba453bf64e90a85c558c6069e15a: FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf) complete. Timing: real 0.015s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6009,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:21.536580 13170 maintenance_manager.cc:419] P ae58ba453bf64e90a85c558c6069e15a: Scheduling MajorDeltaCompactionOp(55428838d95c4daa9e566c71f38e65cf): perf score=1.000000
I20260812 06:20:21.688154 13060 maintenance_manager.cc:643] P ae58ba453bf64e90a85c558c6069e15a: MajorDeltaCompactionOp(55428838d95c4daa9e566c71f38e65cf) complete. Timing: real 0.151s	user 0.123s	sys 0.019s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":256,"lbm_read_time_us":8540,"lbm_reads_lt_1ms":564,"lbm_write_time_us":27701,"lbm_writes_lt_1ms":543,"mutex_wait_us":48,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:20:21.688867 13170 maintenance_manager.cc:419] P ae58ba453bf64e90a85c558c6069e15a: Scheduling FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf): perf score=14.095187
I20260812 06:20:21.725230 13060 maintenance_manager.cc:643] P ae58ba453bf64e90a85c558c6069e15a: FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf) complete. Timing: real 0.036s	user 0.022s	sys 0.012s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":16159,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:21.725780 13170 maintenance_manager.cc:419] P ae58ba453bf64e90a85c558c6069e15a: Scheduling MajorDeltaCompactionOp(55428838d95c4daa9e566c71f38e65cf): perf score=1.000000
I20260812 06:20:21.864845 13060 maintenance_manager.cc:643] P ae58ba453bf64e90a85c558c6069e15a: MajorDeltaCompactionOp(55428838d95c4daa9e566c71f38e65cf) complete. Timing: real 0.139s	user 0.091s	sys 0.044s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672158,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":143,"lbm_read_time_us":8534,"lbm_reads_lt_1ms":467,"lbm_write_time_us":22040,"lbm_writes_lt_1ms":443,"mutex_wait_us":63,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2048,"update_count":2000}
I20260812 06:20:21.865448 13170 maintenance_manager.cc:419] P ae58ba453bf64e90a85c558c6069e15a: Scheduling FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf): perf score=11.118625
I20260812 06:20:21.900137 13060 maintenance_manager.cc:643] P ae58ba453bf64e90a85c558c6069e15a: FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf) complete. Timing: real 0.034s	user 0.034s	sys 0.000s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":13938,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:21.900723 13170 maintenance_manager.cc:419] P ae58ba453bf64e90a85c558c6069e15a: Scheduling FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf): perf score=2.188937
I20260812 06:20:21.923122 13060 maintenance_manager.cc:643] P ae58ba453bf64e90a85c558c6069e15a: FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf) complete. Timing: real 0.022s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3905,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:21.923619 13170 maintenance_manager.cc:419] P ae58ba453bf64e90a85c558c6069e15a: Scheduling FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf): perf score=2.188937
I20260812 06:20:21.933837 13060 maintenance_manager.cc:643] P ae58ba453bf64e90a85c558c6069e15a: FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3700,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:21.934489 13170 maintenance_manager.cc:419] P ae58ba453bf64e90a85c558c6069e15a: Scheduling MajorDeltaCompactionOp(55428838d95c4daa9e566c71f38e65cf): perf score=1.000000
I20260812 06:20:22.106592 13060 maintenance_manager.cc:643] P ae58ba453bf64e90a85c558c6069e15a: MajorDeltaCompactionOp(55428838d95c4daa9e566c71f38e65cf) complete. Timing: real 0.172s	user 0.094s	sys 0.067s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774800,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":294,"lbm_read_time_us":9801,"lbm_reads_lt_1ms":573,"lbm_write_time_us":26927,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:20:22.107273 13170 maintenance_manager.cc:419] P ae58ba453bf64e90a85c558c6069e15a: Scheduling FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf): perf score=14.095187
I20260812 06:20:22.158702 13060 maintenance_manager.cc:643] P ae58ba453bf64e90a85c558c6069e15a: FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf) complete. Timing: real 0.051s	user 0.030s	sys 0.011s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19284,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:22.159226 13170 maintenance_manager.cc:419] P ae58ba453bf64e90a85c558c6069e15a: Scheduling FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf): perf score=2.188937
I20260812 06:20:22.174887 13060 maintenance_manager.cc:643] P ae58ba453bf64e90a85c558c6069e15a: FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf) complete. Timing: real 0.015s	user 0.002s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6008,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.175478 13170 maintenance_manager.cc:419] P ae58ba453bf64e90a85c558c6069e15a: Scheduling MajorDeltaCompactionOp(55428838d95c4daa9e566c71f38e65cf): perf score=1.000000
I20260812 06:20:22.321588 13060 maintenance_manager.cc:643] P ae58ba453bf64e90a85c558c6069e15a: MajorDeltaCompactionOp(55428838d95c4daa9e566c71f38e65cf) complete. Timing: real 0.146s	user 0.100s	sys 0.037s 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":155,"lbm_read_time_us":10793,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25123,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":2500}
I20260812 06:20:22.322188 13170 maintenance_manager.cc:419] P ae58ba453bf64e90a85c558c6069e15a: Scheduling FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf): perf score=11.118625
I20260812 06:20:22.356624 13060 maintenance_manager.cc:643] P ae58ba453bf64e90a85c558c6069e15a: FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf) complete. Timing: real 0.034s	user 0.022s	sys 0.011s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":14300,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:20:22.357148 13170 maintenance_manager.cc:419] P ae58ba453bf64e90a85c558c6069e15a: Scheduling FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf): perf score=2.188937
I20260812 06:20:22.379029 13060 maintenance_manager.cc:643] P ae58ba453bf64e90a85c558c6069e15a: FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf) complete. Timing: real 0.022s	user 0.007s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4806,"lbm_writes_lt_1ms":93,"reinsert_count":0,"spinlock_wait_cycles":1920,"update_count":450}
I20260812 06:20:22.379530 13170 maintenance_manager.cc:419] P ae58ba453bf64e90a85c558c6069e15a: Scheduling FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf): perf score=2.188937
I20260812 06:20:22.389257 13060 maintenance_manager.cc:643] P ae58ba453bf64e90a85c558c6069e15a: FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf) complete. Timing: real 0.010s	user 0.001s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3642,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.389705 13170 maintenance_manager.cc:419] P ae58ba453bf64e90a85c558c6069e15a: Scheduling MajorDeltaCompactionOp(55428838d95c4daa9e566c71f38e65cf): perf score=1.000000
I20260812 06:20:22.527324 13060 maintenance_manager.cc:643] P ae58ba453bf64e90a85c558c6069e15a: MajorDeltaCompactionOp(55428838d95c4daa9e566c71f38e65cf) complete. Timing: real 0.137s	user 0.107s	sys 0.025s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774799,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":508,"lbm_read_time_us":8397,"lbm_reads_lt_1ms":573,"lbm_write_time_us":26543,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:20:22.527943 13170 maintenance_manager.cc:419] P ae58ba453bf64e90a85c558c6069e15a: Scheduling FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf): perf score=11.118625
I20260812 06:20:22.572521 13060 maintenance_manager.cc:643] P ae58ba453bf64e90a85c558c6069e15a: FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf) complete. Timing: real 0.044s	user 0.018s	sys 0.024s Metrics: {"bytes_written":12717737,"delete_count":0,"lbm_write_time_us":18590,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:20:22.572988 13170 maintenance_manager.cc:419] P ae58ba453bf64e90a85c558c6069e15a: Scheduling FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf): perf score=2.188937
I20260812 06:20:22.590898 13060 maintenance_manager.cc:643] P ae58ba453bf64e90a85c558c6069e15a: FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf) complete. Timing: real 0.018s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6103,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.591415 13170 maintenance_manager.cc:419] P ae58ba453bf64e90a85c558c6069e15a: Scheduling FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf): perf score=2.188937
I20260812 06:20:22.600221 13060 maintenance_manager.cc:643] P ae58ba453bf64e90a85c558c6069e15a: FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf) complete. Timing: real 0.009s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3126,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:22.600785 13170 maintenance_manager.cc:419] P ae58ba453bf64e90a85c558c6069e15a: Scheduling FlushMRSOp(55428838d95c4daa9e566c71f38e65cf): perf score=1.000000
I20260812 06:20:22.629896 13060 maintenance_manager.cc:643] P ae58ba453bf64e90a85c558c6069e15a: FlushMRSOp(55428838d95c4daa9e566c71f38e65cf) complete. Timing: real 0.029s	user 0.027s	sys 0.000s Metrics: {"bytes_written":1275445,"cfile_init":1,"dirs.queue_time_us":54,"dirs.run_cpu_time_us":188,"dirs.run_wall_time_us":1734,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1573,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:20:22.630677 13170 maintenance_manager.cc:419] P ae58ba453bf64e90a85c558c6069e15a: Scheduling LogGCOp(55428838d95c4daa9e566c71f38e65cf): free 124257433 bytes of WAL
I20260812 06:20:22.630909 13060 log_reader.cc:385] T 55428838d95c4daa9e566c71f38e65cf: removed 12 log segments from log reader
I20260812 06:20:22.630978 13060 log.cc:1079] T 55428838d95c4daa9e566c71f38e65cf P ae58ba453bf64e90a85c558c6069e15a: Deleting log segment in path: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618190838-12892-0/minicluster-data/ts-0-root/wals/55428838d95c4daa9e566c71f38e65cf/wal-000000026 (ops 125-129)
I20260812 06:20:22.631022 13060 log.cc:1079] T 55428838d95c4daa9e566c71f38e65cf P ae58ba453bf64e90a85c558c6069e15a: Deleting log segment in path: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618190838-12892-0/minicluster-data/ts-0-root/wals/55428838d95c4daa9e566c71f38e65cf/wal-000000027 (ops 130-134)
I20260812 06:20:22.631055 13060 log.cc:1079] T 55428838d95c4daa9e566c71f38e65cf P ae58ba453bf64e90a85c558c6069e15a: Deleting log segment in path: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618190838-12892-0/minicluster-data/ts-0-root/wals/55428838d95c4daa9e566c71f38e65cf/wal-000000028 (ops 135-138)
I20260812 06:20:22.631088 13060 log.cc:1079] T 55428838d95c4daa9e566c71f38e65cf P ae58ba453bf64e90a85c558c6069e15a: Deleting log segment in path: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618190838-12892-0/minicluster-data/ts-0-root/wals/55428838d95c4daa9e566c71f38e65cf/wal-000000029 (ops 139-143)
I20260812 06:20:22.631115 13060 log.cc:1079] T 55428838d95c4daa9e566c71f38e65cf P ae58ba453bf64e90a85c558c6069e15a: Deleting log segment in path: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618190838-12892-0/minicluster-data/ts-0-root/wals/55428838d95c4daa9e566c71f38e65cf/wal-000000030 (ops 144-148)
I20260812 06:20:22.631141 13060 log.cc:1079] T 55428838d95c4daa9e566c71f38e65cf P ae58ba453bf64e90a85c558c6069e15a: Deleting log segment in path: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618190838-12892-0/minicluster-data/ts-0-root/wals/55428838d95c4daa9e566c71f38e65cf/wal-000000031 (ops 149-153)
I20260812 06:20:22.631170 13060 log.cc:1079] T 55428838d95c4daa9e566c71f38e65cf P ae58ba453bf64e90a85c558c6069e15a: Deleting log segment in path: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618190838-12892-0/minicluster-data/ts-0-root/wals/55428838d95c4daa9e566c71f38e65cf/wal-000000032 (ops 154-158)
I20260812 06:20:22.631201 13060 log.cc:1079] T 55428838d95c4daa9e566c71f38e65cf P ae58ba453bf64e90a85c558c6069e15a: Deleting log segment in path: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618190838-12892-0/minicluster-data/ts-0-root/wals/55428838d95c4daa9e566c71f38e65cf/wal-000000033 (ops 159-163)
I20260812 06:20:22.631232 13060 log.cc:1079] T 55428838d95c4daa9e566c71f38e65cf P ae58ba453bf64e90a85c558c6069e15a: Deleting log segment in path: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618190838-12892-0/minicluster-data/ts-0-root/wals/55428838d95c4daa9e566c71f38e65cf/wal-000000034 (ops 164-168)
I20260812 06:20:22.631259 13060 log.cc:1079] T 55428838d95c4daa9e566c71f38e65cf P ae58ba453bf64e90a85c558c6069e15a: Deleting log segment in path: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618190838-12892-0/minicluster-data/ts-0-root/wals/55428838d95c4daa9e566c71f38e65cf/wal-000000035 (ops 169-173)
I20260812 06:20:22.631285 13060 log.cc:1079] T 55428838d95c4daa9e566c71f38e65cf P ae58ba453bf64e90a85c558c6069e15a: Deleting log segment in path: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618190838-12892-0/minicluster-data/ts-0-root/wals/55428838d95c4daa9e566c71f38e65cf/wal-000000036 (ops 174-178)
I20260812 06:20:22.631312 13060 log.cc:1079] T 55428838d95c4daa9e566c71f38e65cf P ae58ba453bf64e90a85c558c6069e15a: Deleting log segment in path: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515618190838-12892-0/minicluster-data/ts-0-root/wals/55428838d95c4daa9e566c71f38e65cf/wal-000000037 (ops 179-183)
I20260812 06:20:22.657178 13060 maintenance_manager.cc:643] P ae58ba453bf64e90a85c558c6069e15a: LogGCOp(55428838d95c4daa9e566c71f38e65cf) complete. Timing: real 0.026s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:20:22.657615 13170 maintenance_manager.cc:419] P ae58ba453bf64e90a85c558c6069e15a: Scheduling UndoDeltaBlockGCOp(55428838d95c4daa9e566c71f38e65cf): 483 bytes on disk
I20260812 06:20:22.658034 13060 maintenance_manager.cc:643] P ae58ba453bf64e90a85c558c6069e15a: UndoDeltaBlockGCOp(55428838d95c4daa9e566c71f38e65cf) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":52,"lbm_reads_lt_1ms":4}
I20260812 06:20:22.658574 13170 maintenance_manager.cc:419] P ae58ba453bf64e90a85c558c6069e15a: Scheduling FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf): perf score=3.181125
I20260812 06:20:22.670984 13060 maintenance_manager.cc:643] P ae58ba453bf64e90a85c558c6069e15a: FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf) complete. Timing: real 0.012s	user 0.004s	sys 0.005s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4080,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:22.671394 13170 maintenance_manager.cc:419] P ae58ba453bf64e90a85c558c6069e15a: Scheduling FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf): perf score=2.188937
I20260812 06:20:22.693389 13060 maintenance_manager.cc:643] P ae58ba453bf64e90a85c558c6069e15a: FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf) complete. Timing: real 0.022s	user 0.005s	sys 0.015s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4852,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:22.693949 13170 maintenance_manager.cc:419] P ae58ba453bf64e90a85c558c6069e15a: Scheduling MajorDeltaCompactionOp(55428838d95c4daa9e566c71f38e65cf): perf score=1.000000
I20260812 06:20:22.895893 13060 maintenance_manager.cc:643] P ae58ba453bf64e90a85c558c6069e15a: MajorDeltaCompactionOp(55428838d95c4daa9e566c71f38e65cf) complete. Timing: real 0.202s	user 0.147s	sys 0.052s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32979850,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":3259,"dirs.run_cpu_time_us":471,"dirs.run_wall_time_us":2820,"lbm_read_time_us":17394,"lbm_reads_lt_1ms":775,"lbm_write_time_us":30644,"lbm_writes_lt_1ms":743,"mutex_wait_us":2644,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":10624,"thread_start_us":98,"threads_started":1,"update_count":3500}
I20260812 06:20:22.896462 13170 maintenance_manager.cc:419] P ae58ba453bf64e90a85c558c6069e15a: Scheduling FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf): perf score=14.095187
I20260812 06:20:22.951575 13060 maintenance_manager.cc:643] P ae58ba453bf64e90a85c558c6069e15a: FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf) complete. Timing: real 0.055s	user 0.033s	sys 0.018s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20829,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:22.952126 13170 maintenance_manager.cc:419] P ae58ba453bf64e90a85c558c6069e15a: Scheduling FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf): perf score=2.188937
I20260812 06:20:22.962956 13060 maintenance_manager.cc:643] P ae58ba453bf64e90a85c558c6069e15a: FlushDeltaMemStoresOp(55428838d95c4daa9e566c71f38e65cf) complete. Timing: real 0.011s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3874,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:22.963447 13170 maintenance_manager.cc:419] P ae58ba453bf64e90a85c558c6069e15a: Scheduling MajorDeltaCompactionOp(55428838d95c4daa9e566c71f38e65cf): perf score=1.000000
I20260812 06:20:22.997488 12892 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.550s	user 1.633s	sys 0.164s
I20260812 06:20:23.073704 12892 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.076s	user 0.001s	sys 0.000s
I20260812 06:20:23.074368 12892 tablet_server.cc:179] TabletServer@127.12.151.1:0 shutting down...
I20260812 06:20:23.117290 13060 maintenance_manager.cc:643] P ae58ba453bf64e90a85c558c6069e15a: MajorDeltaCompactionOp(55428838d95c4daa9e566c71f38e65cf) complete. Timing: real 0.154s	user 0.123s	sys 0.030s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":650,"lbm_read_time_us":12359,"lbm_reads_lt_1ms":568,"lbm_write_time_us":25297,"lbm_writes_lt_1ms":543,"mutex_wait_us":283,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12672,"update_count":2500}
I20260812 06:20:23.117863 12892 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:23.118261 12892 tablet_replica.cc:333] T 55428838d95c4daa9e566c71f38e65cf P ae58ba453bf64e90a85c558c6069e15a: stopping tablet replica
I20260812 06:20:23.118481 12892 raft_consensus.cc:2243] T 55428838d95c4daa9e566c71f38e65cf P ae58ba453bf64e90a85c558c6069e15a [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:23.118692 12892 raft_consensus.cc:2272] T 55428838d95c4daa9e566c71f38e65cf P ae58ba453bf64e90a85c558c6069e15a [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:23.135252 12892 tablet_server.cc:196] TabletServer@127.12.151.1:0 shutdown complete.
I20260812 06:20:23.161999 12892 master.cc:562] Master@127.12.151.62:42039 shutting down...
I20260812 06:20:23.165172 12892 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 083a7b399527483ba8fac8306d1fd923 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:23.165352 12892 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 083a7b399527483ba8fac8306d1fd923 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:23.165423 12892 tablet_replica.cc:333] T 00000000000000000000000000000000 P 083a7b399527483ba8fac8306d1fd923: stopping tablet replica
I20260812 06:20:23.177513 12892 master.cc:584] Master@127.12.151.62:42039 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5049 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:20:23.261426 12892 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.12.151.62:34639
I20260812 06:20:23.261842 12892 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:23.263844 13216 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:23.263916 13219 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:23.263973 12892 server_base.cc:1061] running on GCE node
W20260812 06:20:23.263926 13215 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:23.264179 12892 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:23.264225 12892 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:23.264245 12892 hybrid_clock.cc:648] HybridClock initialized: now 1786515623264244 us; error 0 us; skew 500 ppm
I20260812 06:20:23.265038 12892 webserver.cc:533] Webserver started at http://127.12.151.62:32773/ using document root <none> and password file <none>
I20260812 06:20:23.265198 12892 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:23.265246 12892 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:23.265327 12892 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:23.265710 12892 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618190838-12892-0/minicluster-data/master-0-root/instance:
uuid: "f762620a6be5401daf569881e5b0daa9"
format_stamp: "Formatted at 2026-08-12 06:20:23 on dist-test-slave-nj21"
I20260812 06:20:23.267149 12892 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:20:23.268051 13225 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:23.268266 12892 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:23.268334 12892 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618190838-12892-0/minicluster-data/master-0-root
uuid: "f762620a6be5401daf569881e5b0daa9"
format_stamp: "Formatted at 2026-08-12 06:20:23 on dist-test-slave-nj21"
I20260812 06:20:23.268406 12892 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618190838-12892-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618190838-12892-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618190838-12892-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:23.275817 12892 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:23.276149 12892 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:23.280053 12892 rpc_server.cc:307] RPC server started. Bound to: 127.12.151.62:34639
I20260812 06:20:23.282745 13314 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.12.151.62:34639 every 8 connection(s)
I20260812 06:20:23.283273 13315 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:23.285049 13315 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P f762620a6be5401daf569881e5b0daa9: Bootstrap starting.
I20260812 06:20:23.285818 13315 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P f762620a6be5401daf569881e5b0daa9: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:23.286736 13315 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P f762620a6be5401daf569881e5b0daa9: No bootstrap required, opened a new log
I20260812 06:20:23.287124 13315 raft_consensus.cc:359] T 00000000000000000000000000000000 P f762620a6be5401daf569881e5b0daa9 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f762620a6be5401daf569881e5b0daa9" member_type: VOTER }
I20260812 06:20:23.287213 13315 raft_consensus.cc:385] T 00000000000000000000000000000000 P f762620a6be5401daf569881e5b0daa9 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:23.287248 13315 raft_consensus.cc:740] T 00000000000000000000000000000000 P f762620a6be5401daf569881e5b0daa9 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: f762620a6be5401daf569881e5b0daa9, State: Initialized, Role: FOLLOWER
I20260812 06:20:23.287386 13315 consensus_queue.cc:260] T 00000000000000000000000000000000 P f762620a6be5401daf569881e5b0daa9 [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: "f762620a6be5401daf569881e5b0daa9" member_type: VOTER }
I20260812 06:20:23.287456 13315 raft_consensus.cc:399] T 00000000000000000000000000000000 P f762620a6be5401daf569881e5b0daa9 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:23.287490 13315 raft_consensus.cc:493] T 00000000000000000000000000000000 P f762620a6be5401daf569881e5b0daa9 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:23.287537 13315 raft_consensus.cc:3060] T 00000000000000000000000000000000 P f762620a6be5401daf569881e5b0daa9 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:23.288236 13315 raft_consensus.cc:515] T 00000000000000000000000000000000 P f762620a6be5401daf569881e5b0daa9 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f762620a6be5401daf569881e5b0daa9" member_type: VOTER }
I20260812 06:20:23.288355 13315 leader_election.cc:304] T 00000000000000000000000000000000 P f762620a6be5401daf569881e5b0daa9 [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: f762620a6be5401daf569881e5b0daa9; no voters: 
I20260812 06:20:23.288535 13315 leader_election.cc:290] T 00000000000000000000000000000000 P f762620a6be5401daf569881e5b0daa9 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:23.288630 13319 raft_consensus.cc:2804] T 00000000000000000000000000000000 P f762620a6be5401daf569881e5b0daa9 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:23.288811 13319 raft_consensus.cc:697] T 00000000000000000000000000000000 P f762620a6be5401daf569881e5b0daa9 [term 1 LEADER]: Becoming Leader. State: Replica: f762620a6be5401daf569881e5b0daa9, State: Running, Role: LEADER
I20260812 06:20:23.288976 13315 sys_catalog.cc:565] T 00000000000000000000000000000000 P f762620a6be5401daf569881e5b0daa9 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:20:23.288949 13319 consensus_queue.cc:237] T 00000000000000000000000000000000 P f762620a6be5401daf569881e5b0daa9 [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: "f762620a6be5401daf569881e5b0daa9" member_type: VOTER }
I20260812 06:20:23.289471 13320 sys_catalog.cc:455] T 00000000000000000000000000000000 P f762620a6be5401daf569881e5b0daa9 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "f762620a6be5401daf569881e5b0daa9" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f762620a6be5401daf569881e5b0daa9" member_type: VOTER } }
I20260812 06:20:23.289506 13321 sys_catalog.cc:455] T 00000000000000000000000000000000 P f762620a6be5401daf569881e5b0daa9 [sys.catalog]: SysCatalogTable state changed. Reason: New leader f762620a6be5401daf569881e5b0daa9. Latest consensus state: current_term: 1 leader_uuid: "f762620a6be5401daf569881e5b0daa9" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "f762620a6be5401daf569881e5b0daa9" member_type: VOTER } }
I20260812 06:20:23.289644 13320 sys_catalog.cc:458] T 00000000000000000000000000000000 P f762620a6be5401daf569881e5b0daa9 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:23.289666 13321 sys_catalog.cc:458] T 00000000000000000000000000000000 P f762620a6be5401daf569881e5b0daa9 [sys.catalog]: This master's current role is: LEADER
I20260812 06:20:23.290179 13335 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:20:23.290807 13335 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:20:23.290959 12892 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:20:23.292470 13335 catalog_manager.cc:1383] Generated new cluster ID: 3158d85f2cd9416caf2daf6e3c17215b
I20260812 06:20:23.292522 13335 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:20:23.310302 13335 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:20:23.310824 13335 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:20:23.320294 13335 catalog_manager.cc:6092] T 00000000000000000000000000000000 P f762620a6be5401daf569881e5b0daa9: Generated new TSK 0
I20260812 06:20:23.320454 13335 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:20:23.323145 12892 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:20:23.324981 13358 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:23.324998 13353 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:23.325109 13354 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:23.325026 12892 server_base.cc:1061] running on GCE node
I20260812 06:20:23.325366 12892 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:20:23.325421 12892 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:23.325443 12892 hybrid_clock.cc:648] HybridClock initialized: now 1786515623325443 us; error 0 us; skew 500 ppm
I20260812 06:20:23.326185 12892 webserver.cc:533] Webserver started at http://127.12.151.1:43599/ using document root <none> and password file <none>
I20260812 06:20:23.326342 12892 fs_manager.cc:362] Metadata directory not provided
I20260812 06:20:23.326385 12892 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:20:23.326439 12892 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:20:23.326778 12892 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618190838-12892-0/minicluster-data/ts-0-root/instance:
uuid: "e395c3fd6ff44474a5b905cbfd4b8b31"
format_stamp: "Formatted at 2026-08-12 06:20:23 on dist-test-slave-nj21"
I20260812 06:20:23.328238 12892 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:20:23.329087 13369 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:23.329335 12892 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:20:23.329406 12892 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618190838-12892-0/minicluster-data/ts-0-root
uuid: "e395c3fd6ff44474a5b905cbfd4b8b31"
format_stamp: "Formatted at 2026-08-12 06:20:23 on dist-test-slave-nj21"
I20260812 06:20:23.329471 12892 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618190838-12892-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618190838-12892-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618190838-12892-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:23.350073 12892 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:20:23.350462 12892 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:20:23.350768 12892 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:20:23.351241 12892 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:20:23.351280 12892 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:23.351325 12892 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:20:23.351357 12892 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:20:23.355476 12892 rpc_server.cc:307] RPC server started. Bound to: 127.12.151.1:36539
I20260812 06:20:23.356415 13477 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.12.151.1:36539 every 8 connection(s)
I20260812 06:20:23.363108 13478 heartbeater.cc:344] Connected to a master server at 127.12.151.62:34639
I20260812 06:20:23.363209 13478 heartbeater.cc:461] Registering TS with master...
I20260812 06:20:23.363412 13478 heartbeater.cc:507] Master 127.12.151.62:34639 requested a full tablet report, sending...
I20260812 06:20:23.364030 13256 ts_manager.cc:194] Registered new tserver with Master: e395c3fd6ff44474a5b905cbfd4b8b31 (127.12.151.1:36539)
I20260812 06:20:23.364714 13256 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:59480
I20260812 06:20:23.364984 12892 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.008785669s
I20260812 06:20:23.371380 13256 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:59488:
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:23.379562 13413 tablet_service.cc:1511] Processing CreateTablet for tablet cd76f83e5dba44bf91296330603b26dd (DEFAULT_TABLE table=heavy-update-compaction-test [id=c5b8ae9e032a4c318245f47243804cf1]), partition=
I20260812 06:20:23.379842 13413 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet cd76f83e5dba44bf91296330603b26dd. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:20:23.381690 13497 tablet_bootstrap.cc:492] T cd76f83e5dba44bf91296330603b26dd P e395c3fd6ff44474a5b905cbfd4b8b31: Bootstrap starting.
I20260812 06:20:23.382558 13497 tablet_bootstrap.cc:654] T cd76f83e5dba44bf91296330603b26dd P e395c3fd6ff44474a5b905cbfd4b8b31: Neither blocks nor log segments found. Creating new log.
I20260812 06:20:23.383497 13497 tablet_bootstrap.cc:492] T cd76f83e5dba44bf91296330603b26dd P e395c3fd6ff44474a5b905cbfd4b8b31: No bootstrap required, opened a new log
I20260812 06:20:23.383570 13497 ts_tablet_manager.cc:1403] T cd76f83e5dba44bf91296330603b26dd P e395c3fd6ff44474a5b905cbfd4b8b31: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:20:23.384001 13497 raft_consensus.cc:359] T cd76f83e5dba44bf91296330603b26dd P e395c3fd6ff44474a5b905cbfd4b8b31 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e395c3fd6ff44474a5b905cbfd4b8b31" member_type: VOTER last_known_addr { host: "127.12.151.1" port: 36539 } }
I20260812 06:20:23.384088 13497 raft_consensus.cc:385] T cd76f83e5dba44bf91296330603b26dd P e395c3fd6ff44474a5b905cbfd4b8b31 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:20:23.384120 13497 raft_consensus.cc:740] T cd76f83e5dba44bf91296330603b26dd P e395c3fd6ff44474a5b905cbfd4b8b31 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: e395c3fd6ff44474a5b905cbfd4b8b31, State: Initialized, Role: FOLLOWER
I20260812 06:20:23.384248 13497 consensus_queue.cc:260] T cd76f83e5dba44bf91296330603b26dd P e395c3fd6ff44474a5b905cbfd4b8b31 [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: "e395c3fd6ff44474a5b905cbfd4b8b31" member_type: VOTER last_known_addr { host: "127.12.151.1" port: 36539 } }
I20260812 06:20:23.384316 13497 raft_consensus.cc:399] T cd76f83e5dba44bf91296330603b26dd P e395c3fd6ff44474a5b905cbfd4b8b31 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:20:23.384358 13497 raft_consensus.cc:493] T cd76f83e5dba44bf91296330603b26dd P e395c3fd6ff44474a5b905cbfd4b8b31 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:20:23.384409 13497 raft_consensus.cc:3060] T cd76f83e5dba44bf91296330603b26dd P e395c3fd6ff44474a5b905cbfd4b8b31 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:20:23.385255 13497 raft_consensus.cc:515] T cd76f83e5dba44bf91296330603b26dd P e395c3fd6ff44474a5b905cbfd4b8b31 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e395c3fd6ff44474a5b905cbfd4b8b31" member_type: VOTER last_known_addr { host: "127.12.151.1" port: 36539 } }
I20260812 06:20:23.385382 13497 leader_election.cc:304] T cd76f83e5dba44bf91296330603b26dd P e395c3fd6ff44474a5b905cbfd4b8b31 [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: e395c3fd6ff44474a5b905cbfd4b8b31; no voters: 
I20260812 06:20:23.385532 13497 leader_election.cc:290] T cd76f83e5dba44bf91296330603b26dd P e395c3fd6ff44474a5b905cbfd4b8b31 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:20:23.385634 13509 raft_consensus.cc:2804] T cd76f83e5dba44bf91296330603b26dd P e395c3fd6ff44474a5b905cbfd4b8b31 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:20:23.385816 13497 ts_tablet_manager.cc:1434] T cd76f83e5dba44bf91296330603b26dd P e395c3fd6ff44474a5b905cbfd4b8b31: Time spent starting tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:20:23.385838 13509 raft_consensus.cc:697] T cd76f83e5dba44bf91296330603b26dd P e395c3fd6ff44474a5b905cbfd4b8b31 [term 1 LEADER]: Becoming Leader. State: Replica: e395c3fd6ff44474a5b905cbfd4b8b31, State: Running, Role: LEADER
I20260812 06:20:23.385867 13478 heartbeater.cc:499] Master 127.12.151.62:34639 was elected leader, sending a full tablet report...
I20260812 06:20:23.385984 13509 consensus_queue.cc:237] T cd76f83e5dba44bf91296330603b26dd P e395c3fd6ff44474a5b905cbfd4b8b31 [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: "e395c3fd6ff44474a5b905cbfd4b8b31" member_type: VOTER last_known_addr { host: "127.12.151.1" port: 36539 } }
I20260812 06:20:23.387243 13256 catalog_manager.cc:5719] T cd76f83e5dba44bf91296330603b26dd P e395c3fd6ff44474a5b905cbfd4b8b31 reported cstate change: term changed from 0 to 1, leader changed from <none> to e395c3fd6ff44474a5b905cbfd4b8b31 (127.12.151.1). New cstate: current_term: 1 leader_uuid: "e395c3fd6ff44474a5b905cbfd4b8b31" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e395c3fd6ff44474a5b905cbfd4b8b31" member_type: VOTER last_known_addr { host: "127.12.151.1" port: 36539 } health_report { overall_health: HEALTHY } } }
I20260812 06:20:23.444819 12892 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.050s	user 0.018s	sys 0.004s
I20260812 06:20:23.606840 13479 maintenance_manager.cc:419] P e395c3fd6ff44474a5b905cbfd4b8b31: Scheduling FlushMRSOp(cd76f83e5dba44bf91296330603b26dd): perf score=23.023690
I20260812 06:20:23.784060 13374 maintenance_manager.cc:643] P e395c3fd6ff44474a5b905cbfd4b8b31: FlushMRSOp(cd76f83e5dba44bf91296330603b26dd) complete. Timing: real 0.177s	user 0.131s	sys 0.036s Metrics: {"bytes_written":13210029,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":50,"dirs.run_cpu_time_us":194,"dirs.run_wall_time_us":844,"drs_written":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4,"lbm_write_time_us":40493,"lbm_writes_lt_1ms":879,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"spinlock_wait_cycles":12544,"update_count":1610}
I20260812 06:20:23.784695 13479 maintenance_manager.cc:419] P e395c3fd6ff44474a5b905cbfd4b8b31: Scheduling LogGCOp(cd76f83e5dba44bf91296330603b26dd): free 20743880 bytes of WAL
I20260812 06:20:23.784927 13374 log_reader.cc:385] T cd76f83e5dba44bf91296330603b26dd: removed 2 log segments from log reader
I20260812 06:20:23.784976 13374 log.cc:1079] T cd76f83e5dba44bf91296330603b26dd P e395c3fd6ff44474a5b905cbfd4b8b31: Deleting log segment in path: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618190838-12892-0/minicluster-data/ts-0-root/wals/cd76f83e5dba44bf91296330603b26dd/wal-000000001 (ops 1-6)
I20260812 06:20:23.785008 13374 log.cc:1079] T cd76f83e5dba44bf91296330603b26dd P e395c3fd6ff44474a5b905cbfd4b8b31: Deleting log segment in path: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618190838-12892-0/minicluster-data/ts-0-root/wals/cd76f83e5dba44bf91296330603b26dd/wal-000000002 (ops 7-11)
I20260812 06:20:23.789978 13374 maintenance_manager.cc:643] P e395c3fd6ff44474a5b905cbfd4b8b31: LogGCOp(cd76f83e5dba44bf91296330603b26dd) complete. Timing: real 0.005s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:20:23.790453 13479 maintenance_manager.cc:419] P e395c3fd6ff44474a5b905cbfd4b8b31: Scheduling FlushDeltaMemStoresOp(cd76f83e5dba44bf91296330603b26dd): perf score=2.188937
I20260812 06:20:23.807718 13374 maintenance_manager.cc:643] P e395c3fd6ff44474a5b905cbfd4b8b31: FlushDeltaMemStoresOp(cd76f83e5dba44bf91296330603b26dd) complete. Timing: real 0.017s	user 0.006s	sys 0.004s Metrics: {"bytes_written":3610359,"delete_count":0,"lbm_write_time_us":3364,"lbm_writes_lt_1ms":91,"reinsert_count":0,"update_count":440}
I20260812 06:20:23.808152 13479 maintenance_manager.cc:419] P e395c3fd6ff44474a5b905cbfd4b8b31: Scheduling UndoDeltaBlockGCOp(cd76f83e5dba44bf91296330603b26dd): 20513815 bytes on disk
I20260812 06:20:23.808544 13374 maintenance_manager.cc:643] P e395c3fd6ff44474a5b905cbfd4b8b31: UndoDeltaBlockGCOp(cd76f83e5dba44bf91296330603b26dd) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":59,"lbm_reads_lt_1ms":4}
I20260812 06:20:23.808934 13479 maintenance_manager.cc:419] P e395c3fd6ff44474a5b905cbfd4b8b31: Scheduling FlushDeltaMemStoresOp(cd76f83e5dba44bf91296330603b26dd): perf score=2.188937
I20260812 06:20:23.817874 13374 maintenance_manager.cc:643] P e395c3fd6ff44474a5b905cbfd4b8b31: FlushDeltaMemStoresOp(cd76f83e5dba44bf91296330603b26dd) complete. Timing: real 0.009s	user 0.000s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3285,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:23.818235 13479 maintenance_manager.cc:419] P e395c3fd6ff44474a5b905cbfd4b8b31: Scheduling MajorDeltaCompactionOp(cd76f83e5dba44bf91296330603b26dd): perf score=1.000000
I20260812 06:20:23.984508 13374 maintenance_manager.cc:643] P e395c3fd6ff44474a5b905cbfd4b8b31: MajorDeltaCompactionOp(cd76f83e5dba44bf91296330603b26dd) complete. Timing: real 0.166s	user 0.118s	sys 0.040s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815788,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":468,"lbm_read_time_us":10171,"lbm_reads_lt_1ms":569,"lbm_write_time_us":27543,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"thread_start_us":318,"threads_started":5,"update_count":2500}
I20260812 06:20:23.985069 13479 maintenance_manager.cc:419] P e395c3fd6ff44474a5b905cbfd4b8b31: Scheduling FlushDeltaMemStoresOp(cd76f83e5dba44bf91296330603b26dd): perf score=14.095187
I20260812 06:20:24.042693 13374 maintenance_manager.cc:643] P e395c3fd6ff44474a5b905cbfd4b8b31: FlushDeltaMemStoresOp(cd76f83e5dba44bf91296330603b26dd) complete. Timing: real 0.057s	user 0.030s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21503,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:24.043388 13479 maintenance_manager.cc:419] P e395c3fd6ff44474a5b905cbfd4b8b31: Scheduling FlushDeltaMemStoresOp(cd76f83e5dba44bf91296330603b26dd): perf score=2.188937
I20260812 06:20:24.054325 13374 maintenance_manager.cc:643] P e395c3fd6ff44474a5b905cbfd4b8b31: FlushDeltaMemStoresOp(cd76f83e5dba44bf91296330603b26dd) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4039,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:24.054927 13479 maintenance_manager.cc:419] P e395c3fd6ff44474a5b905cbfd4b8b31: Scheduling MajorDeltaCompactionOp(cd76f83e5dba44bf91296330603b26dd): perf score=1.000000
I20260812 06:20:24.222481 13374 maintenance_manager.cc:643] P e395c3fd6ff44474a5b905cbfd4b8b31: MajorDeltaCompactionOp(cd76f83e5dba44bf91296330603b26dd) complete. Timing: real 0.167s	user 0.115s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":742,"lbm_read_time_us":13355,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26267,"lbm_writes_lt_1ms":543,"mutex_wait_us":507,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14720,"update_count":2500}
I20260812 06:20:24.223043 13479 maintenance_manager.cc:419] P e395c3fd6ff44474a5b905cbfd4b8b31: Scheduling FlushDeltaMemStoresOp(cd76f83e5dba44bf91296330603b26dd): perf score=14.095187
I20260812 06:20:24.283555 13374 maintenance_manager.cc:643] P e395c3fd6ff44474a5b905cbfd4b8b31: FlushDeltaMemStoresOp(cd76f83e5dba44bf91296330603b26dd) complete. Timing: real 0.060s	user 0.024s	sys 0.031s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22325,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:24.284077 13479 maintenance_manager.cc:419] P e395c3fd6ff44474a5b905cbfd4b8b31: Scheduling FlushDeltaMemStoresOp(cd76f83e5dba44bf91296330603b26dd): perf score=2.188937
I20260812 06:20:24.294319 13374 maintenance_manager.cc:643] P e395c3fd6ff44474a5b905cbfd4b8b31: FlushDeltaMemStoresOp(cd76f83e5dba44bf91296330603b26dd) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3915,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:24.294780 13479 maintenance_manager.cc:419] P e395c3fd6ff44474a5b905cbfd4b8b31: Scheduling MajorDeltaCompactionOp(cd76f83e5dba44bf91296330603b26dd): perf score=1.000000
I20260812 06:20:24.487844 13374 maintenance_manager.cc:643] P e395c3fd6ff44474a5b905cbfd4b8b31: MajorDeltaCompactionOp(cd76f83e5dba44bf91296330603b26dd) complete. Timing: real 0.193s	user 0.111s	sys 0.080s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":748,"lbm_read_time_us":12217,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32606,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:20:24.488438 13479 maintenance_manager.cc:419] P e395c3fd6ff44474a5b905cbfd4b8b31: Scheduling FlushDeltaMemStoresOp(cd76f83e5dba44bf91296330603b26dd): perf score=10.126437
I20260812 06:20:24.532799 13374 maintenance_manager.cc:643] P e395c3fd6ff44474a5b905cbfd4b8b31: FlushDeltaMemStoresOp(cd76f83e5dba44bf91296330603b26dd) complete. Timing: real 0.044s	user 0.032s	sys 0.009s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17563,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:24.533216 13479 maintenance_manager.cc:419] P e395c3fd6ff44474a5b905cbfd4b8b31: Scheduling FlushDeltaMemStoresOp(cd76f83e5dba44bf91296330603b26dd): perf score=2.188937
I20260812 06:20:24.548429 13374 maintenance_manager.cc:643] P e395c3fd6ff44474a5b905cbfd4b8b31: FlushDeltaMemStoresOp(cd76f83e5dba44bf91296330603b26dd) complete. Timing: real 0.015s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5766,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:24.548986 13479 maintenance_manager.cc:419] P e395c3fd6ff44474a5b905cbfd4b8b31: Scheduling MajorDeltaCompactionOp(cd76f83e5dba44bf91296330603b26dd): perf score=1.000000
I20260812 06:20:24.699414 13374 maintenance_manager.cc:643] P e395c3fd6ff44474a5b905cbfd4b8b31: MajorDeltaCompactionOp(cd76f83e5dba44bf91296330603b26dd) complete. Timing: real 0.150s	user 0.098s	sys 0.045s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":233,"lbm_read_time_us":9229,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21712,"lbm_writes_lt_1ms":443,"mutex_wait_us":37,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:20:24.699990 13479 maintenance_manager.cc:419] P e395c3fd6ff44474a5b905cbfd4b8b31: Scheduling FlushDeltaMemStoresOp(cd76f83e5dba44bf91296330603b26dd): perf score=10.126437
I20260812 06:20:24.734890 13374 maintenance_manager.cc:643] P e395c3fd6ff44474a5b905cbfd4b8b31: FlushDeltaMemStoresOp(cd76f83e5dba44bf91296330603b26dd) complete. Timing: real 0.035s	user 0.017s	sys 0.011s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":13311,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:24.735316 13479 maintenance_manager.cc:419] P e395c3fd6ff44474a5b905cbfd4b8b31: Scheduling FlushDeltaMemStoresOp(cd76f83e5dba44bf91296330603b26dd): perf score=2.188937
I20260812 06:20:24.745069 13374 maintenance_manager.cc:643] P e395c3fd6ff44474a5b905cbfd4b8b31: FlushDeltaMemStoresOp(cd76f83e5dba44bf91296330603b26dd) complete. Timing: real 0.010s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3785,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:24.745496 13479 maintenance_manager.cc:419] P e395c3fd6ff44474a5b905cbfd4b8b31: Scheduling MajorDeltaCompactionOp(cd76f83e5dba44bf91296330603b26dd): perf score=1.000000
I20260812 06:20:24.875202 13374 maintenance_manager.cc:643] P e395c3fd6ff44474a5b905cbfd4b8b31: MajorDeltaCompactionOp(cd76f83e5dba44bf91296330603b26dd) complete. Timing: real 0.130s	user 0.093s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713274,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":707,"lbm_read_time_us":10834,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24050,"lbm_writes_lt_1ms":443,"mutex_wait_us":310,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9344,"update_count":2000}
I20260812 06:20:24.875849 13479 maintenance_manager.cc:419] P e395c3fd6ff44474a5b905cbfd4b8b31: Scheduling FlushDeltaMemStoresOp(cd76f83e5dba44bf91296330603b26dd): perf score=10.126437
I20260812 06:20:24.918337 13374 maintenance_manager.cc:643] P e395c3fd6ff44474a5b905cbfd4b8b31: FlushDeltaMemStoresOp(cd76f83e5dba44bf91296330603b26dd) complete. Timing: real 0.042s	user 0.018s	sys 0.021s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19475,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:20:24.918802 13479 maintenance_manager.cc:419] P e395c3fd6ff44474a5b905cbfd4b8b31: Scheduling FlushDeltaMemStoresOp(cd76f83e5dba44bf91296330603b26dd): perf score=2.188937
I20260812 06:20:24.929454 13374 maintenance_manager.cc:643] P e395c3fd6ff44474a5b905cbfd4b8b31: FlushDeltaMemStoresOp(cd76f83e5dba44bf91296330603b26dd) complete. Timing: real 0.010s	user 0.004s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3604,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:24.929955 13479 maintenance_manager.cc:419] P e395c3fd6ff44474a5b905cbfd4b8b31: Scheduling MajorDeltaCompactionOp(cd76f83e5dba44bf91296330603b26dd): perf score=1.000000
I20260812 06:20:25.055614 13374 maintenance_manager.cc:643] P e395c3fd6ff44474a5b905cbfd4b8b31: MajorDeltaCompactionOp(cd76f83e5dba44bf91296330603b26dd) complete. Timing: real 0.126s	user 0.096s	sys 0.029s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713271,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":918,"lbm_read_time_us":8682,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23647,"lbm_writes_lt_1ms":443,"mutex_wait_us":275,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12800,"update_count":2000}
I20260812 06:20:25.056218 13479 maintenance_manager.cc:419] P e395c3fd6ff44474a5b905cbfd4b8b31: Scheduling FlushDeltaMemStoresOp(cd76f83e5dba44bf91296330603b26dd): perf score=10.126437
I20260812 06:20:25.101773 13374 maintenance_manager.cc:643] P e395c3fd6ff44474a5b905cbfd4b8b31: FlushDeltaMemStoresOp(cd76f83e5dba44bf91296330603b26dd) complete. Timing: real 0.045s	user 0.026s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13824,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:20:25.102312 13479 maintenance_manager.cc:419] P e395c3fd6ff44474a5b905cbfd4b8b31: Scheduling FlushDeltaMemStoresOp(cd76f83e5dba44bf91296330603b26dd): perf score=2.188937
I20260812 06:20:25.117527 13374 maintenance_manager.cc:643] P e395c3fd6ff44474a5b905cbfd4b8b31: FlushDeltaMemStoresOp(cd76f83e5dba44bf91296330603b26dd) complete. Timing: real 0.015s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5802,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:25.118094 13479 maintenance_manager.cc:419] P e395c3fd6ff44474a5b905cbfd4b8b31: Scheduling FlushMRSOp(cd76f83e5dba44bf91296330603b26dd): perf score=1.000000
I20260812 06:20:25.145866 13374 maintenance_manager.cc:643] P e395c3fd6ff44474a5b905cbfd4b8b31: FlushMRSOp(cd76f83e5dba44bf91296330603b26dd) complete. Timing: real 0.028s	user 0.026s	sys 0.000s Metrics: {"bytes_written":1275444,"cfile_init":1,"dirs.queue_time_us":66,"dirs.run_cpu_time_us":254,"dirs.run_wall_time_us":1129,"drs_written":1,"lbm_read_time_us":42,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1281,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:20:25.146471 13479 maintenance_manager.cc:419] P e395c3fd6ff44474a5b905cbfd4b8b31: Scheduling UndoDeltaBlockGCOp(cd76f83e5dba44bf91296330603b26dd): 485 bytes on disk
I20260812 06:20:25.147043 13374 maintenance_manager.cc:643] P e395c3fd6ff44474a5b905cbfd4b8b31: UndoDeltaBlockGCOp(cd76f83e5dba44bf91296330603b26dd) 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:25.147519 13479 maintenance_manager.cc:419] P e395c3fd6ff44474a5b905cbfd4b8b31: Scheduling MajorDeltaCompactionOp(cd76f83e5dba44bf91296330603b26dd): perf score=1.000000
I20260812 06:20:25.287055 13374 maintenance_manager.cc:643] P e395c3fd6ff44474a5b905cbfd4b8b31: MajorDeltaCompactionOp(cd76f83e5dba44bf91296330603b26dd) complete. Timing: real 0.139s	user 0.084s	sys 0.047s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713272,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":391,"lbm_read_time_us":8917,"lbm_reads_lt_1ms":464,"lbm_write_time_us":20402,"lbm_writes_lt_1ms":443,"mutex_wait_us":86,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:20:25.287572 13479 maintenance_manager.cc:419] P e395c3fd6ff44474a5b905cbfd4b8b31: Scheduling LogGCOp(cd76f83e5dba44bf91296330603b26dd): free 133024352 bytes of WAL
I20260812 06:20:25.287802 13374 log_reader.cc:385] T cd76f83e5dba44bf91296330603b26dd: removed 13 log segments from log reader
I20260812 06:20:25.287881 13374 log.cc:1079] T cd76f83e5dba44bf91296330603b26dd P e395c3fd6ff44474a5b905cbfd4b8b31: Deleting log segment in path: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618190838-12892-0/minicluster-data/ts-0-root/wals/cd76f83e5dba44bf91296330603b26dd/wal-000000003 (ops 12-16)
I20260812 06:20:25.287936 13374 log.cc:1079] T cd76f83e5dba44bf91296330603b26dd P e395c3fd6ff44474a5b905cbfd4b8b31: Deleting log segment in path: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618190838-12892-0/minicluster-data/ts-0-root/wals/cd76f83e5dba44bf91296330603b26dd/wal-000000004 (ops 17-21)
I20260812 06:20:25.287974 13374 log.cc:1079] T cd76f83e5dba44bf91296330603b26dd P e395c3fd6ff44474a5b905cbfd4b8b31: Deleting log segment in path: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618190838-12892-0/minicluster-data/ts-0-root/wals/cd76f83e5dba44bf91296330603b26dd/wal-000000005 (ops 22-26)
I20260812 06:20:25.288033 13374 log.cc:1079] T cd76f83e5dba44bf91296330603b26dd P e395c3fd6ff44474a5b905cbfd4b8b31: Deleting log segment in path: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618190838-12892-0/minicluster-data/ts-0-root/wals/cd76f83e5dba44bf91296330603b26dd/wal-000000006 (ops 27-30)
I20260812 06:20:25.288069 13374 log.cc:1079] T cd76f83e5dba44bf91296330603b26dd P e395c3fd6ff44474a5b905cbfd4b8b31: Deleting log segment in path: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618190838-12892-0/minicluster-data/ts-0-root/wals/cd76f83e5dba44bf91296330603b26dd/wal-000000007 (ops 31-35)
I20260812 06:20:25.288092 13374 log.cc:1079] T cd76f83e5dba44bf91296330603b26dd P e395c3fd6ff44474a5b905cbfd4b8b31: Deleting log segment in path: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618190838-12892-0/minicluster-data/ts-0-root/wals/cd76f83e5dba44bf91296330603b26dd/wal-000000008 (ops 36-40)
I20260812 06:20:25.288147 13374 log.cc:1079] T cd76f83e5dba44bf91296330603b26dd P e395c3fd6ff44474a5b905cbfd4b8b31: Deleting log segment in path: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618190838-12892-0/minicluster-data/ts-0-root/wals/cd76f83e5dba44bf91296330603b26dd/wal-000000009 (ops 41-45)
I20260812 06:20:25.288182 13374 log.cc:1079] T cd76f83e5dba44bf91296330603b26dd P e395c3fd6ff44474a5b905cbfd4b8b31: Deleting log segment in path: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618190838-12892-0/minicluster-data/ts-0-root/wals/cd76f83e5dba44bf91296330603b26dd/wal-000000010 (ops 46-50)
I20260812 06:20:25.288205 13374 log.cc:1079] T cd76f83e5dba44bf91296330603b26dd P e395c3fd6ff44474a5b905cbfd4b8b31: Deleting log segment in path: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618190838-12892-0/minicluster-data/ts-0-root/wals/cd76f83e5dba44bf91296330603b26dd/wal-000000011 (ops 51-55)
I20260812 06:20:25.288259 13374 log.cc:1079] T cd76f83e5dba44bf91296330603b26dd P e395c3fd6ff44474a5b905cbfd4b8b31: Deleting log segment in path: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618190838-12892-0/minicluster-data/ts-0-root/wals/cd76f83e5dba44bf91296330603b26dd/wal-000000012 (ops 56-60)
I20260812 06:20:25.288293 13374 log.cc:1079] T cd76f83e5dba44bf91296330603b26dd P e395c3fd6ff44474a5b905cbfd4b8b31: Deleting log segment in path: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618190838-12892-0/minicluster-data/ts-0-root/wals/cd76f83e5dba44bf91296330603b26dd/wal-000000013 (ops 61-65)
I20260812 06:20:25.288353 13374 log.cc:1079] T cd76f83e5dba44bf91296330603b26dd P e395c3fd6ff44474a5b905cbfd4b8b31: Deleting log segment in path: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618190838-12892-0/minicluster-data/ts-0-root/wals/cd76f83e5dba44bf91296330603b26dd/wal-000000014 (ops 66-70)
I20260812 06:20:25.288389 13374 log.cc:1079] T cd76f83e5dba44bf91296330603b26dd P e395c3fd6ff44474a5b905cbfd4b8b31: Deleting log segment in path: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618190838-12892-0/minicluster-data/ts-0-root/wals/cd76f83e5dba44bf91296330603b26dd/wal-000000015 (ops 71-75)
I20260812 06:20:25.310693 13374 maintenance_manager.cc:643] P e395c3fd6ff44474a5b905cbfd4b8b31: LogGCOp(cd76f83e5dba44bf91296330603b26dd) complete. Timing: real 0.023s	user 0.000s	sys 0.020s Metrics: {}
I20260812 06:20:25.311174 13479 maintenance_manager.cc:419] P e395c3fd6ff44474a5b905cbfd4b8b31: Scheduling FlushDeltaMemStoresOp(cd76f83e5dba44bf91296330603b26dd): perf score=14.095187
I20260812 06:20:25.354635 13374 maintenance_manager.cc:643] P e395c3fd6ff44474a5b905cbfd4b8b31: FlushDeltaMemStoresOp(cd76f83e5dba44bf91296330603b26dd) complete. Timing: real 0.043s	user 0.028s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18688,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:25.355127 13479 maintenance_manager.cc:419] P e395c3fd6ff44474a5b905cbfd4b8b31: Scheduling FlushDeltaMemStoresOp(cd76f83e5dba44bf91296330603b26dd): perf score=3.181125
I20260812 06:20:25.380976 13374 maintenance_manager.cc:643] P e395c3fd6ff44474a5b905cbfd4b8b31: FlushDeltaMemStoresOp(cd76f83e5dba44bf91296330603b26dd) complete. Timing: real 0.026s	user 0.007s	sys 0.010s Metrics: {"bytes_written":4471876,"delete_count":0,"lbm_write_time_us":4175,"lbm_writes_lt_1ms":112,"reinsert_count":0,"update_count":545}
I20260812 06:20:25.381467 13479 maintenance_manager.cc:419] P e395c3fd6ff44474a5b905cbfd4b8b31: Scheduling FlushDeltaMemStoresOp(cd76f83e5dba44bf91296330603b26dd): perf score=2.188937
I20260812 06:20:25.390990 13374 maintenance_manager.cc:643] P e395c3fd6ff44474a5b905cbfd4b8b31: FlushDeltaMemStoresOp(cd76f83e5dba44bf91296330603b26dd) complete. Timing: real 0.009s	user 0.000s	sys 0.008s Metrics: {"bytes_written":3733434,"delete_count":0,"lbm_write_time_us":3548,"lbm_writes_lt_1ms":94,"reinsert_count":0,"update_count":455}
I20260812 06:20:25.391420 13479 maintenance_manager.cc:419] P e395c3fd6ff44474a5b905cbfd4b8b31: Scheduling MajorDeltaCompactionOp(cd76f83e5dba44bf91296330603b26dd): perf score=1.000000
I20260812 06:20:25.589938 13374 maintenance_manager.cc:643] P e395c3fd6ff44474a5b905cbfd4b8b31: MajorDeltaCompactionOp(cd76f83e5dba44bf91296330603b26dd) complete. Timing: real 0.198s	user 0.123s	sys 0.074s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918206,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":850,"lbm_read_time_us":13722,"lbm_reads_lt_1ms":673,"lbm_write_time_us":32718,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3072,"update_count":3000}
I20260812 06:20:25.590431 13479 maintenance_manager.cc:419] P e395c3fd6ff44474a5b905cbfd4b8b31: Scheduling FlushDeltaMemStoresOp(cd76f83e5dba44bf91296330603b26dd): perf score=14.095187
I20260812 06:20:25.647267 13374 maintenance_manager.cc:643] P e395c3fd6ff44474a5b905cbfd4b8b31: FlushDeltaMemStoresOp(cd76f83e5dba44bf91296330603b26dd) complete. Timing: real 0.056s	user 0.030s	sys 0.018s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18097,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:25.647869 13479 maintenance_manager.cc:419] P e395c3fd6ff44474a5b905cbfd4b8b31: Scheduling FlushDeltaMemStoresOp(cd76f83e5dba44bf91296330603b26dd): perf score=2.188937
I20260812 06:20:25.662803 13374 maintenance_manager.cc:643] P e395c3fd6ff44474a5b905cbfd4b8b31: FlushDeltaMemStoresOp(cd76f83e5dba44bf91296330603b26dd) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5798,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:25.663286 13479 maintenance_manager.cc:419] P e395c3fd6ff44474a5b905cbfd4b8b31: Scheduling MajorDeltaCompactionOp(cd76f83e5dba44bf91296330603b26dd): perf score=1.000000
I20260812 06:20:25.839764 13374 maintenance_manager.cc:643] P e395c3fd6ff44474a5b905cbfd4b8b31: MajorDeltaCompactionOp(cd76f83e5dba44bf91296330603b26dd) complete. Timing: real 0.176s	user 0.093s	sys 0.071s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":148,"lbm_read_time_us":12045,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26428,"lbm_writes_lt_1ms":543,"mutex_wait_us":21,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11648,"update_count":2500}
I20260812 06:20:25.840291 13479 maintenance_manager.cc:419] P e395c3fd6ff44474a5b905cbfd4b8b31: Scheduling FlushDeltaMemStoresOp(cd76f83e5dba44bf91296330603b26dd): perf score=14.095187
I20260812 06:20:25.886713 13374 maintenance_manager.cc:643] P e395c3fd6ff44474a5b905cbfd4b8b31: FlushDeltaMemStoresOp(cd76f83e5dba44bf91296330603b26dd) complete. Timing: real 0.046s	user 0.025s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19041,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:25.887360 13479 maintenance_manager.cc:419] P e395c3fd6ff44474a5b905cbfd4b8b31: Scheduling FlushDeltaMemStoresOp(cd76f83e5dba44bf91296330603b26dd): perf score=2.188937
I20260812 06:20:25.910629 13374 maintenance_manager.cc:643] P e395c3fd6ff44474a5b905cbfd4b8b31: FlushDeltaMemStoresOp(cd76f83e5dba44bf91296330603b26dd) complete. Timing: real 0.023s	user 0.010s	sys 0.010s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6093,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:25.911201 13479 maintenance_manager.cc:419] P e395c3fd6ff44474a5b905cbfd4b8b31: Scheduling MajorDeltaCompactionOp(cd76f83e5dba44bf91296330603b26dd): perf score=1.000000
I20260812 06:20:26.095232 13374 maintenance_manager.cc:643] P e395c3fd6ff44474a5b905cbfd4b8b31: MajorDeltaCompactionOp(cd76f83e5dba44bf91296330603b26dd) complete. Timing: real 0.184s	user 0.129s	sys 0.049s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":790,"lbm_read_time_us":13306,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29223,"lbm_writes_lt_1ms":543,"mutex_wait_us":278,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14080,"update_count":2500}
I20260812 06:20:26.095727 13479 maintenance_manager.cc:419] P e395c3fd6ff44474a5b905cbfd4b8b31: Scheduling FlushDeltaMemStoresOp(cd76f83e5dba44bf91296330603b26dd): perf score=14.095187
I20260812 06:20:26.142099 13374 maintenance_manager.cc:643] P e395c3fd6ff44474a5b905cbfd4b8b31: FlushDeltaMemStoresOp(cd76f83e5dba44bf91296330603b26dd) complete. Timing: real 0.046s	user 0.018s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19000,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:26.142621 13479 maintenance_manager.cc:419] P e395c3fd6ff44474a5b905cbfd4b8b31: Scheduling FlushDeltaMemStoresOp(cd76f83e5dba44bf91296330603b26dd): perf score=2.188937
I20260812 06:20:26.157779 13374 maintenance_manager.cc:643] P e395c3fd6ff44474a5b905cbfd4b8b31: FlushDeltaMemStoresOp(cd76f83e5dba44bf91296330603b26dd) complete. Timing: real 0.015s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5671,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:26.158330 13479 maintenance_manager.cc:419] P e395c3fd6ff44474a5b905cbfd4b8b31: Scheduling MajorDeltaCompactionOp(cd76f83e5dba44bf91296330603b26dd): perf score=1.000000
I20260812 06:20:26.343096 13374 maintenance_manager.cc:643] P e395c3fd6ff44474a5b905cbfd4b8b31: MajorDeltaCompactionOp(cd76f83e5dba44bf91296330603b26dd) complete. Timing: real 0.185s	user 0.099s	sys 0.069s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":187,"lbm_read_time_us":11070,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27687,"lbm_writes_lt_1ms":543,"mutex_wait_us":36,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10624,"update_count":2500}
I20260812 06:20:26.343652 13479 maintenance_manager.cc:419] P e395c3fd6ff44474a5b905cbfd4b8b31: Scheduling FlushDeltaMemStoresOp(cd76f83e5dba44bf91296330603b26dd): perf score=14.095187
I20260812 06:20:26.391309 13374 maintenance_manager.cc:643] P e395c3fd6ff44474a5b905cbfd4b8b31: FlushDeltaMemStoresOp(cd76f83e5dba44bf91296330603b26dd) complete. Timing: real 0.047s	user 0.030s	sys 0.009s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18281,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:26.391892 13479 maintenance_manager.cc:419] P e395c3fd6ff44474a5b905cbfd4b8b31: Scheduling FlushDeltaMemStoresOp(cd76f83e5dba44bf91296330603b26dd): perf score=2.188937
I20260812 06:20:26.406929 13374 maintenance_manager.cc:643] P e395c3fd6ff44474a5b905cbfd4b8b31: FlushDeltaMemStoresOp(cd76f83e5dba44bf91296330603b26dd) complete. Timing: real 0.015s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5774,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:26.407441 13479 maintenance_manager.cc:419] P e395c3fd6ff44474a5b905cbfd4b8b31: Scheduling MajorDeltaCompactionOp(cd76f83e5dba44bf91296330603b26dd): perf score=1.000000
I20260812 06:20:26.560214 13374 maintenance_manager.cc:643] P e395c3fd6ff44474a5b905cbfd4b8b31: MajorDeltaCompactionOp(cd76f83e5dba44bf91296330603b26dd) complete. Timing: real 0.153s	user 0.105s	sys 0.035s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":163,"lbm_read_time_us":9756,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27557,"lbm_writes_lt_1ms":543,"mutex_wait_us":40,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7552,"update_count":2500}
I20260812 06:20:26.560801 13479 maintenance_manager.cc:419] P e395c3fd6ff44474a5b905cbfd4b8b31: Scheduling FlushDeltaMemStoresOp(cd76f83e5dba44bf91296330603b26dd): perf score=14.095187
I20260812 06:20:26.605095 13374 maintenance_manager.cc:643] P e395c3fd6ff44474a5b905cbfd4b8b31: FlushDeltaMemStoresOp(cd76f83e5dba44bf91296330603b26dd) complete. Timing: real 0.044s	user 0.026s	sys 0.011s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":16506,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:26.605578 13479 maintenance_manager.cc:419] P e395c3fd6ff44474a5b905cbfd4b8b31: Scheduling FlushDeltaMemStoresOp(cd76f83e5dba44bf91296330603b26dd): perf score=2.188937
I20260812 06:20:26.615902 13374 maintenance_manager.cc:643] P e395c3fd6ff44474a5b905cbfd4b8b31: FlushDeltaMemStoresOp(cd76f83e5dba44bf91296330603b26dd) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3777,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:26.616513 13479 maintenance_manager.cc:419] P e395c3fd6ff44474a5b905cbfd4b8b31: Scheduling FlushMRSOp(cd76f83e5dba44bf91296330603b26dd): perf score=1.000000
I20260812 06:20:26.648357 13374 maintenance_manager.cc:643] P e395c3fd6ff44474a5b905cbfd4b8b31: FlushMRSOp(cd76f83e5dba44bf91296330603b26dd) complete. Timing: real 0.032s	user 0.027s	sys 0.004s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":49,"dirs.run_cpu_time_us":195,"dirs.run_wall_time_us":1231,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1494,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:20:26.648969 13479 maintenance_manager.cc:419] P e395c3fd6ff44474a5b905cbfd4b8b31: Scheduling LogGCOp(cd76f83e5dba44bf91296330603b26dd): free 124257274 bytes of WAL
I20260812 06:20:26.649179 13374 log_reader.cc:385] T cd76f83e5dba44bf91296330603b26dd: removed 12 log segments from log reader
I20260812 06:20:26.649221 13374 log.cc:1079] T cd76f83e5dba44bf91296330603b26dd P e395c3fd6ff44474a5b905cbfd4b8b31: Deleting log segment in path: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618190838-12892-0/minicluster-data/ts-0-root/wals/cd76f83e5dba44bf91296330603b26dd/wal-000000016 (ops 76-80)
I20260812 06:20:26.649250 13374 log.cc:1079] T cd76f83e5dba44bf91296330603b26dd P e395c3fd6ff44474a5b905cbfd4b8b31: Deleting log segment in path: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618190838-12892-0/minicluster-data/ts-0-root/wals/cd76f83e5dba44bf91296330603b26dd/wal-000000017 (ops 81-85)
I20260812 06:20:26.649281 13374 log.cc:1079] T cd76f83e5dba44bf91296330603b26dd P e395c3fd6ff44474a5b905cbfd4b8b31: Deleting log segment in path: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618190838-12892-0/minicluster-data/ts-0-root/wals/cd76f83e5dba44bf91296330603b26dd/wal-000000018 (ops 86-90)
I20260812 06:20:26.649312 13374 log.cc:1079] T cd76f83e5dba44bf91296330603b26dd P e395c3fd6ff44474a5b905cbfd4b8b31: Deleting log segment in path: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618190838-12892-0/minicluster-data/ts-0-root/wals/cd76f83e5dba44bf91296330603b26dd/wal-000000019 (ops 91-95)
I20260812 06:20:26.649345 13374 log.cc:1079] T cd76f83e5dba44bf91296330603b26dd P e395c3fd6ff44474a5b905cbfd4b8b31: Deleting log segment in path: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618190838-12892-0/minicluster-data/ts-0-root/wals/cd76f83e5dba44bf91296330603b26dd/wal-000000020 (ops 96-100)
I20260812 06:20:26.649376 13374 log.cc:1079] T cd76f83e5dba44bf91296330603b26dd P e395c3fd6ff44474a5b905cbfd4b8b31: Deleting log segment in path: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618190838-12892-0/minicluster-data/ts-0-root/wals/cd76f83e5dba44bf91296330603b26dd/wal-000000021 (ops 101-105)
I20260812 06:20:26.649408 13374 log.cc:1079] T cd76f83e5dba44bf91296330603b26dd P e395c3fd6ff44474a5b905cbfd4b8b31: Deleting log segment in path: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618190838-12892-0/minicluster-data/ts-0-root/wals/cd76f83e5dba44bf91296330603b26dd/wal-000000022 (ops 106-110)
I20260812 06:20:26.649439 13374 log.cc:1079] T cd76f83e5dba44bf91296330603b26dd P e395c3fd6ff44474a5b905cbfd4b8b31: Deleting log segment in path: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618190838-12892-0/minicluster-data/ts-0-root/wals/cd76f83e5dba44bf91296330603b26dd/wal-000000023 (ops 111-114)
I20260812 06:20:26.649470 13374 log.cc:1079] T cd76f83e5dba44bf91296330603b26dd P e395c3fd6ff44474a5b905cbfd4b8b31: Deleting log segment in path: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618190838-12892-0/minicluster-data/ts-0-root/wals/cd76f83e5dba44bf91296330603b26dd/wal-000000024 (ops 115-119)
I20260812 06:20:26.649516 13374 log.cc:1079] T cd76f83e5dba44bf91296330603b26dd P e395c3fd6ff44474a5b905cbfd4b8b31: Deleting log segment in path: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618190838-12892-0/minicluster-data/ts-0-root/wals/cd76f83e5dba44bf91296330603b26dd/wal-000000025 (ops 120-124)
I20260812 06:20:26.649547 13374 log.cc:1079] T cd76f83e5dba44bf91296330603b26dd P e395c3fd6ff44474a5b905cbfd4b8b31: Deleting log segment in path: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618190838-12892-0/minicluster-data/ts-0-root/wals/cd76f83e5dba44bf91296330603b26dd/wal-000000026 (ops 125-129)
I20260812 06:20:26.649580 13374 log.cc:1079] T cd76f83e5dba44bf91296330603b26dd P e395c3fd6ff44474a5b905cbfd4b8b31: Deleting log segment in path: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618190838-12892-0/minicluster-data/ts-0-root/wals/cd76f83e5dba44bf91296330603b26dd/wal-000000027 (ops 130-134)
I20260812 06:20:26.670363 13374 maintenance_manager.cc:643] P e395c3fd6ff44474a5b905cbfd4b8b31: LogGCOp(cd76f83e5dba44bf91296330603b26dd) complete. Timing: real 0.021s	user 0.001s	sys 0.019s Metrics: {}
I20260812 06:20:26.670812 13479 maintenance_manager.cc:419] P e395c3fd6ff44474a5b905cbfd4b8b31: Scheduling FlushDeltaMemStoresOp(cd76f83e5dba44bf91296330603b26dd): perf score=3.181125
I20260812 06:20:26.688262 13374 maintenance_manager.cc:643] P e395c3fd6ff44474a5b905cbfd4b8b31: FlushDeltaMemStoresOp(cd76f83e5dba44bf91296330603b26dd) complete. Timing: real 0.017s	user 0.016s	sys 0.000s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":6741,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:20:26.688706 13479 maintenance_manager.cc:419] P e395c3fd6ff44474a5b905cbfd4b8b31: Scheduling FlushDeltaMemStoresOp(cd76f83e5dba44bf91296330603b26dd): perf score=2.188937
I20260812 06:20:26.705358 13374 maintenance_manager.cc:643] P e395c3fd6ff44474a5b905cbfd4b8b31: FlushDeltaMemStoresOp(cd76f83e5dba44bf91296330603b26dd) complete. Timing: real 0.016s	user 0.005s	sys 0.010s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3324,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:20:26.705856 13479 maintenance_manager.cc:419] P e395c3fd6ff44474a5b905cbfd4b8b31: Scheduling UndoDeltaBlockGCOp(cd76f83e5dba44bf91296330603b26dd): 482 bytes on disk
I20260812 06:20:26.706290 13374 maintenance_manager.cc:643] P e395c3fd6ff44474a5b905cbfd4b8b31: UndoDeltaBlockGCOp(cd76f83e5dba44bf91296330603b26dd) 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:26.706779 13479 maintenance_manager.cc:419] P e395c3fd6ff44474a5b905cbfd4b8b31: Scheduling MajorDeltaCompactionOp(cd76f83e5dba44bf91296330603b26dd): perf score=1.000000
I20260812 06:20:26.932709 13374 maintenance_manager.cc:643] P e395c3fd6ff44474a5b905cbfd4b8b31: MajorDeltaCompactionOp(cd76f83e5dba44bf91296330603b26dd) complete. Timing: real 0.226s	user 0.135s	sys 0.082s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020733,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1730,"lbm_read_time_us":15214,"lbm_reads_lt_1ms":774,"lbm_write_time_us":34086,"lbm_writes_lt_1ms":743,"mutex_wait_us":28,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":3584,"thread_start_us":70,"threads_started":1,"update_count":3500}
I20260812 06:20:26.933598 13479 maintenance_manager.cc:419] P e395c3fd6ff44474a5b905cbfd4b8b31: Scheduling FlushDeltaMemStoresOp(cd76f83e5dba44bf91296330603b26dd): perf score=18.063937
I20260812 06:20:26.993291 13374 maintenance_manager.cc:643] P e395c3fd6ff44474a5b905cbfd4b8b31: FlushDeltaMemStoresOp(cd76f83e5dba44bf91296330603b26dd) complete. Timing: real 0.059s	user 0.024s	sys 0.030s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":24388,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:26.993818 13479 maintenance_manager.cc:419] P e395c3fd6ff44474a5b905cbfd4b8b31: Scheduling FlushDeltaMemStoresOp(cd76f83e5dba44bf91296330603b26dd): perf score=2.188937
I20260812 06:20:27.009056 13374 maintenance_manager.cc:643] P e395c3fd6ff44474a5b905cbfd4b8b31: FlushDeltaMemStoresOp(cd76f83e5dba44bf91296330603b26dd) complete. Timing: real 0.015s	user 0.004s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5707,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:27.009577 13479 maintenance_manager.cc:419] P e395c3fd6ff44474a5b905cbfd4b8b31: Scheduling MajorDeltaCompactionOp(cd76f83e5dba44bf91296330603b26dd): perf score=1.000000
I20260812 06:20:27.206032 13374 maintenance_manager.cc:643] P e395c3fd6ff44474a5b905cbfd4b8b31: MajorDeltaCompactionOp(cd76f83e5dba44bf91296330603b26dd) complete. Timing: real 0.196s	user 0.123s	sys 0.071s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918097,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":126,"lbm_read_time_us":15096,"lbm_reads_lt_1ms":672,"lbm_write_time_us":31031,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":3000}
I20260812 06:20:27.206625 13479 maintenance_manager.cc:419] P e395c3fd6ff44474a5b905cbfd4b8b31: Scheduling FlushDeltaMemStoresOp(cd76f83e5dba44bf91296330603b26dd): perf score=14.095187
I20260812 06:20:27.276556 13374 maintenance_manager.cc:643] P e395c3fd6ff44474a5b905cbfd4b8b31: FlushDeltaMemStoresOp(cd76f83e5dba44bf91296330603b26dd) complete. Timing: real 0.066s	user 0.018s	sys 0.036s Metrics: {"bytes_written":16820141,"delete_count":0,"lbm_write_time_us":25630,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":412,"reinsert_count":0,"update_count":2050}
I20260812 06:20:27.277000 13479 maintenance_manager.cc:419] P e395c3fd6ff44474a5b905cbfd4b8b31: Scheduling FlushDeltaMemStoresOp(cd76f83e5dba44bf91296330603b26dd): perf score=6.157687
I20260812 06:20:27.298224 13374 maintenance_manager.cc:643] P e395c3fd6ff44474a5b905cbfd4b8b31: FlushDeltaMemStoresOp(cd76f83e5dba44bf91296330603b26dd) complete. Timing: real 0.021s	user 0.005s	sys 0.013s Metrics: {"bytes_written":7794836,"delete_count":0,"lbm_write_time_us":8204,"lbm_writes_lt_1ms":193,"reinsert_count":0,"update_count":950}
I20260812 06:20:27.298817 13479 maintenance_manager.cc:419] P e395c3fd6ff44474a5b905cbfd4b8b31: Scheduling MajorDeltaCompactionOp(cd76f83e5dba44bf91296330603b26dd): perf score=1.000000
I20260812 06:20:27.487454 13374 maintenance_manager.cc:643] P e395c3fd6ff44474a5b905cbfd4b8b31: MajorDeltaCompactionOp(cd76f83e5dba44bf91296330603b26dd) complete. Timing: real 0.188s	user 0.112s	sys 0.060s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918094,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":201,"lbm_read_time_us":11670,"lbm_reads_lt_1ms":668,"lbm_write_time_us":28736,"lbm_writes_lt_1ms":643,"mutex_wait_us":44,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":3000}
I20260812 06:20:27.487952 13479 maintenance_manager.cc:419] P e395c3fd6ff44474a5b905cbfd4b8b31: Scheduling FlushDeltaMemStoresOp(cd76f83e5dba44bf91296330603b26dd): perf score=18.063937
I20260812 06:20:27.541275 13374 maintenance_manager.cc:643] P e395c3fd6ff44474a5b905cbfd4b8b31: FlushDeltaMemStoresOp(cd76f83e5dba44bf91296330603b26dd) complete. Timing: real 0.053s	user 0.036s	sys 0.015s Metrics: {"bytes_written":20512319,"delete_count":0,"lbm_write_time_us":23338,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:20:27.541767 13479 maintenance_manager.cc:419] P e395c3fd6ff44474a5b905cbfd4b8b31: Scheduling FlushDeltaMemStoresOp(cd76f83e5dba44bf91296330603b26dd): perf score=2.188937
I20260812 06:20:27.552013 13374 maintenance_manager.cc:643] P e395c3fd6ff44474a5b905cbfd4b8b31: FlushDeltaMemStoresOp(cd76f83e5dba44bf91296330603b26dd) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3778,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:27.552664 13479 maintenance_manager.cc:419] P e395c3fd6ff44474a5b905cbfd4b8b31: Scheduling MajorDeltaCompactionOp(cd76f83e5dba44bf91296330603b26dd): perf score=1.000000
I20260812 06:20:27.719125 13374 maintenance_manager.cc:643] P e395c3fd6ff44474a5b905cbfd4b8b31: MajorDeltaCompactionOp(cd76f83e5dba44bf91296330603b26dd) complete. Timing: real 0.166s	user 0.121s	sys 0.044s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918100,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1216,"lbm_read_time_us":11611,"lbm_reads_lt_1ms":672,"lbm_write_time_us":27678,"lbm_writes_lt_1ms":643,"mutex_wait_us":441,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":13568,"update_count":3000}
I20260812 06:20:27.719765 13479 maintenance_manager.cc:419] P e395c3fd6ff44474a5b905cbfd4b8b31: Scheduling FlushDeltaMemStoresOp(cd76f83e5dba44bf91296330603b26dd): perf score=14.095187
I20260812 06:20:27.763242 13374 maintenance_manager.cc:643] P e395c3fd6ff44474a5b905cbfd4b8b31: FlushDeltaMemStoresOp(cd76f83e5dba44bf91296330603b26dd) complete. Timing: real 0.042s	user 0.017s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18266,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:27.763787 13479 maintenance_manager.cc:419] P e395c3fd6ff44474a5b905cbfd4b8b31: Scheduling FlushDeltaMemStoresOp(cd76f83e5dba44bf91296330603b26dd): perf score=2.188937
I20260812 06:20:27.789350 13374 maintenance_manager.cc:643] P e395c3fd6ff44474a5b905cbfd4b8b31: FlushDeltaMemStoresOp(cd76f83e5dba44bf91296330603b26dd) complete. Timing: real 0.025s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5115,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:27.789852 13479 maintenance_manager.cc:419] P e395c3fd6ff44474a5b905cbfd4b8b31: Scheduling FlushDeltaMemStoresOp(cd76f83e5dba44bf91296330603b26dd): perf score=2.188937
I20260812 06:20:27.799860 13374 maintenance_manager.cc:643] P e395c3fd6ff44474a5b905cbfd4b8b31: FlushDeltaMemStoresOp(cd76f83e5dba44bf91296330603b26dd) complete. Timing: real 0.010s	user 0.004s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3724,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:27.800447 13479 maintenance_manager.cc:419] P e395c3fd6ff44474a5b905cbfd4b8b31: Scheduling MajorDeltaCompactionOp(cd76f83e5dba44bf91296330603b26dd): perf score=1.000000
I20260812 06:20:27.963716 13374 maintenance_manager.cc:643] P e395c3fd6ff44474a5b905cbfd4b8b31: MajorDeltaCompactionOp(cd76f83e5dba44bf91296330603b26dd) complete. Timing: real 0.163s	user 0.116s	sys 0.044s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918214,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1156,"lbm_read_time_us":10438,"lbm_reads_lt_1ms":673,"lbm_write_time_us":34398,"lbm_writes_lt_1ms":643,"mutex_wait_us":25,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":11264,"update_count":3000}
I20260812 06:20:27.964327 13479 maintenance_manager.cc:419] P e395c3fd6ff44474a5b905cbfd4b8b31: Scheduling FlushDeltaMemStoresOp(cd76f83e5dba44bf91296330603b26dd): perf score=14.095187
I20260812 06:20:28.005044 13374 maintenance_manager.cc:643] P e395c3fd6ff44474a5b905cbfd4b8b31: FlushDeltaMemStoresOp(cd76f83e5dba44bf91296330603b26dd) complete. Timing: real 0.040s	user 0.029s	sys 0.010s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":17628,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:20:28.005613 13479 maintenance_manager.cc:419] P e395c3fd6ff44474a5b905cbfd4b8b31: Scheduling FlushDeltaMemStoresOp(cd76f83e5dba44bf91296330603b26dd): perf score=2.188937
I20260812 06:20:28.021358 13374 maintenance_manager.cc:643] P e395c3fd6ff44474a5b905cbfd4b8b31: FlushDeltaMemStoresOp(cd76f83e5dba44bf91296330603b26dd) complete. Timing: real 0.016s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5894,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:28.023790 13479 maintenance_manager.cc:419] P e395c3fd6ff44474a5b905cbfd4b8b31: Scheduling FlushMRSOp(cd76f83e5dba44bf91296330603b26dd): perf score=1.000000
I20260812 06:20:28.057626 13374 maintenance_manager.cc:643] P e395c3fd6ff44474a5b905cbfd4b8b31: FlushMRSOp(cd76f83e5dba44bf91296330603b26dd) complete. Timing: real 0.033s	user 0.027s	sys 0.001s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":55,"dirs.run_cpu_time_us":182,"dirs.run_wall_time_us":1141,"drs_written":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1938,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:20:28.058434 13479 maintenance_manager.cc:419] P e395c3fd6ff44474a5b905cbfd4b8b31: Scheduling LogGCOp(cd76f83e5dba44bf91296330603b26dd): free 133477650 bytes of WAL
I20260812 06:20:28.058676 13374 log_reader.cc:385] T cd76f83e5dba44bf91296330603b26dd: removed 13 log segments from log reader
I20260812 06:20:28.058739 13374 log.cc:1079] T cd76f83e5dba44bf91296330603b26dd P e395c3fd6ff44474a5b905cbfd4b8b31: Deleting log segment in path: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618190838-12892-0/minicluster-data/ts-0-root/wals/cd76f83e5dba44bf91296330603b26dd/wal-000000028 (ops 135-139)
I20260812 06:20:28.058779 13374 log.cc:1079] T cd76f83e5dba44bf91296330603b26dd P e395c3fd6ff44474a5b905cbfd4b8b31: Deleting log segment in path: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618190838-12892-0/minicluster-data/ts-0-root/wals/cd76f83e5dba44bf91296330603b26dd/wal-000000029 (ops 140-144)
I20260812 06:20:28.058810 13374 log.cc:1079] T cd76f83e5dba44bf91296330603b26dd P e395c3fd6ff44474a5b905cbfd4b8b31: Deleting log segment in path: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618190838-12892-0/minicluster-data/ts-0-root/wals/cd76f83e5dba44bf91296330603b26dd/wal-000000030 (ops 145-149)
I20260812 06:20:28.058832 13374 log.cc:1079] T cd76f83e5dba44bf91296330603b26dd P e395c3fd6ff44474a5b905cbfd4b8b31: Deleting log segment in path: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618190838-12892-0/minicluster-data/ts-0-root/wals/cd76f83e5dba44bf91296330603b26dd/wal-000000031 (ops 150-154)
I20260812 06:20:28.058862 13374 log.cc:1079] T cd76f83e5dba44bf91296330603b26dd P e395c3fd6ff44474a5b905cbfd4b8b31: Deleting log segment in path: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618190838-12892-0/minicluster-data/ts-0-root/wals/cd76f83e5dba44bf91296330603b26dd/wal-000000032 (ops 155-159)
I20260812 06:20:28.058894 13374 log.cc:1079] T cd76f83e5dba44bf91296330603b26dd P e395c3fd6ff44474a5b905cbfd4b8b31: Deleting log segment in path: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618190838-12892-0/minicluster-data/ts-0-root/wals/cd76f83e5dba44bf91296330603b26dd/wal-000000033 (ops 160-164)
I20260812 06:20:28.058926 13374 log.cc:1079] T cd76f83e5dba44bf91296330603b26dd P e395c3fd6ff44474a5b905cbfd4b8b31: Deleting log segment in path: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618190838-12892-0/minicluster-data/ts-0-root/wals/cd76f83e5dba44bf91296330603b26dd/wal-000000034 (ops 165-169)
I20260812 06:20:28.058959 13374 log.cc:1079] T cd76f83e5dba44bf91296330603b26dd P e395c3fd6ff44474a5b905cbfd4b8b31: Deleting log segment in path: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618190838-12892-0/minicluster-data/ts-0-root/wals/cd76f83e5dba44bf91296330603b26dd/wal-000000035 (ops 170-174)
I20260812 06:20:28.058985 13374 log.cc:1079] T cd76f83e5dba44bf91296330603b26dd P e395c3fd6ff44474a5b905cbfd4b8b31: Deleting log segment in path: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618190838-12892-0/minicluster-data/ts-0-root/wals/cd76f83e5dba44bf91296330603b26dd/wal-000000036 (ops 175-179)
I20260812 06:20:28.059015 13374 log.cc:1079] T cd76f83e5dba44bf91296330603b26dd P e395c3fd6ff44474a5b905cbfd4b8b31: Deleting log segment in path: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618190838-12892-0/minicluster-data/ts-0-root/wals/cd76f83e5dba44bf91296330603b26dd/wal-000000037 (ops 180-184)
I20260812 06:20:28.059044 13374 log.cc:1079] T cd76f83e5dba44bf91296330603b26dd P e395c3fd6ff44474a5b905cbfd4b8b31: Deleting log segment in path: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618190838-12892-0/minicluster-data/ts-0-root/wals/cd76f83e5dba44bf91296330603b26dd/wal-000000038 (ops 185-189)
I20260812 06:20:28.059075 13374 log.cc:1079] T cd76f83e5dba44bf91296330603b26dd P e395c3fd6ff44474a5b905cbfd4b8b31: Deleting log segment in path: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618190838-12892-0/minicluster-data/ts-0-root/wals/cd76f83e5dba44bf91296330603b26dd/wal-000000039 (ops 190-194)
I20260812 06:20:28.059108 13374 log.cc:1079] T cd76f83e5dba44bf91296330603b26dd P e395c3fd6ff44474a5b905cbfd4b8b31: Deleting log segment in path: /tmp/dist-test-taskiO_qqT/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515618190838-12892-0/minicluster-data/ts-0-root/wals/cd76f83e5dba44bf91296330603b26dd/wal-000000040 (ops 195-199)
I20260812 06:20:28.083461 13374 maintenance_manager.cc:643] P e395c3fd6ff44474a5b905cbfd4b8b31: LogGCOp(cd76f83e5dba44bf91296330603b26dd) complete. Timing: real 0.025s	user 0.001s	sys 0.020s Metrics: {}
I20260812 06:20:28.083926 13479 maintenance_manager.cc:419] P e395c3fd6ff44474a5b905cbfd4b8b31: Scheduling UndoDeltaBlockGCOp(cd76f83e5dba44bf91296330603b26dd): 482 bytes on disk
I20260812 06:20:28.084686 13374 maintenance_manager.cc:643] P e395c3fd6ff44474a5b905cbfd4b8b31: UndoDeltaBlockGCOp(cd76f83e5dba44bf91296330603b26dd) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":66,"lbm_reads_lt_1ms":4}
I20260812 06:20:28.085235 13479 maintenance_manager.cc:419] P e395c3fd6ff44474a5b905cbfd4b8b31: Scheduling FlushDeltaMemStoresOp(cd76f83e5dba44bf91296330603b26dd): perf score=2.188937
I20260812 06:20:28.102526 12892 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.658s	user 1.717s	sys 0.134s
I20260812 06:20:28.103971 13374 maintenance_manager.cc:643] P e395c3fd6ff44474a5b905cbfd4b8b31: FlushDeltaMemStoresOp(cd76f83e5dba44bf91296330603b26dd) complete. Timing: real 0.019s	user 0.011s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6420,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:28.104364 13479 maintenance_manager.cc:419] P e395c3fd6ff44474a5b905cbfd4b8b31: Scheduling FlushDeltaMemStoresOp(cd76f83e5dba44bf91296330603b26dd): perf score=2.188937
I20260812 06:20:28.113686 13374 maintenance_manager.cc:643] P e395c3fd6ff44474a5b905cbfd4b8b31: FlushDeltaMemStoresOp(cd76f83e5dba44bf91296330603b26dd) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3640,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:20:28.114130 13479 maintenance_manager.cc:419] P e395c3fd6ff44474a5b905cbfd4b8b31: Scheduling MajorDeltaCompactionOp(cd76f83e5dba44bf91296330603b26dd): perf score=1.000000
I20260812 06:20:28.157387 12892 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.054s	user 0.001s	sys 0.000s
I20260812 06:20:28.157891 12892 tablet_server.cc:179] TabletServer@127.12.151.1:0 shutting down...
I20260812 06:20:28.254643 13374 maintenance_manager.cc:643] P e395c3fd6ff44474a5b905cbfd4b8b31: MajorDeltaCompactionOp(cd76f83e5dba44bf91296330603b26dd) complete. Timing: real 0.140s	user 0.096s	sys 0.044s Metrics: {"cfile_cache_hit":386,"cfile_cache_hit_bytes":15715444,"cfile_cache_miss":348,"cfile_cache_miss_bytes":17305302,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1208,"lbm_read_time_us":7082,"lbm_reads_lt_1ms":380,"lbm_write_time_us":29937,"lbm_writes_lt_1ms":743,"mutex_wait_us":453,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":58624,"thread_start_us":74,"threads_started":1,"update_count":3500}
I20260812 06:20:28.255849 12892 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:20:28.256091 12892 tablet_replica.cc:333] T cd76f83e5dba44bf91296330603b26dd P e395c3fd6ff44474a5b905cbfd4b8b31: stopping tablet replica
I20260812 06:20:28.256211 12892 raft_consensus.cc:2243] T cd76f83e5dba44bf91296330603b26dd P e395c3fd6ff44474a5b905cbfd4b8b31 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:28.256373 12892 raft_consensus.cc:2272] T cd76f83e5dba44bf91296330603b26dd P e395c3fd6ff44474a5b905cbfd4b8b31 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:28.260417 12892 tablet_server.cc:196] TabletServer@127.12.151.1:0 shutdown complete.
I20260812 06:20:28.310542 12892 master.cc:562] Master@127.12.151.62:34639 shutting down...
I20260812 06:20:28.313997 12892 raft_consensus.cc:2243] T 00000000000000000000000000000000 P f762620a6be5401daf569881e5b0daa9 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:20:28.314172 12892 raft_consensus.cc:2272] T 00000000000000000000000000000000 P f762620a6be5401daf569881e5b0daa9 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:20:28.314242 12892 tablet_replica.cc:333] T 00000000000000000000000000000000 P f762620a6be5401daf569881e5b0daa9: stopping tablet replica
I20260812 06:20:28.327405 12892 master.cc:584] Master@127.12.151.62:34639 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5144 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10195 ms total)

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