[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:17:11.132234   757 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.0.189.126:33087
I20260812 06:17:11.133304   757 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:17:11.133946   757 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:11.141402   765 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:11.141469   762 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:17:11.141542   763 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:17:11.142020   757 server_base.cc:1061] running on GCE node
I20260812 06:17:11.142601   757 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:11.142694   757 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:11.142726   757 hybrid_clock.cc:648] HybridClock initialized: now 1786515431142724 us; error 0 us; skew 500 ppm
I20260812 06:17:11.144711   757 webserver.cc:533] Webserver started at http://127.0.189.126:41409/ using document root <none> and password file <none>
I20260812 06:17:11.145236   757 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:11.145385   757 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:11.145689   757 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:11.147608   757 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431121259-757-0/minicluster-data/master-0-root/instance:
uuid: "98063d1e69ee4a7081bc0c5135c9281d"
format_stamp: "Formatted at 2026-08-12 06:17:11 on dist-test-slave-zpfg"
I20260812 06:17:11.151628   757 fs_manager.cc:696] Time spent creating directory manager: real 0.004s	user 0.004s	sys 0.000s
I20260812 06:17:11.154078   770 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:11.155362   757 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.001s
I20260812 06:17:11.155512   757 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431121259-757-0/minicluster-data/master-0-root
uuid: "98063d1e69ee4a7081bc0c5135c9281d"
format_stamp: "Formatted at 2026-08-12 06:17:11 on dist-test-slave-zpfg"
I20260812 06:17:11.155629   757 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431121259-757-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431121259-757-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431121259-757-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:11.171758   757 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:11.172473   757 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:17:11.172664   757 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:11.180970   757 rpc_server.cc:307] RPC server started. Bound to: 127.0.189.126:33087
I20260812 06:17:11.180976   825 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.0.189.126:33087 every 8 connection(s)
I20260812 06:17:11.183380   826 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:11.189200   826 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 98063d1e69ee4a7081bc0c5135c9281d: Bootstrap starting.
I20260812 06:17:11.191712   826 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 98063d1e69ee4a7081bc0c5135c9281d: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:11.192724   826 log.cc:826] T 00000000000000000000000000000000 P 98063d1e69ee4a7081bc0c5135c9281d: Log is configured to *not* fsync() on all Append() calls
I20260812 06:17:11.194837   826 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 98063d1e69ee4a7081bc0c5135c9281d: No bootstrap required, opened a new log
I20260812 06:17:11.197948   826 raft_consensus.cc:359] T 00000000000000000000000000000000 P 98063d1e69ee4a7081bc0c5135c9281d [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "98063d1e69ee4a7081bc0c5135c9281d" member_type: VOTER }
I20260812 06:17:11.198134   826 raft_consensus.cc:385] T 00000000000000000000000000000000 P 98063d1e69ee4a7081bc0c5135c9281d [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:11.198231   826 raft_consensus.cc:740] T 00000000000000000000000000000000 P 98063d1e69ee4a7081bc0c5135c9281d [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 98063d1e69ee4a7081bc0c5135c9281d, State: Initialized, Role: FOLLOWER
I20260812 06:17:11.198951   826 consensus_queue.cc:260] T 00000000000000000000000000000000 P 98063d1e69ee4a7081bc0c5135c9281d [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: "98063d1e69ee4a7081bc0c5135c9281d" member_type: VOTER }
I20260812 06:17:11.199138   826 raft_consensus.cc:399] T 00000000000000000000000000000000 P 98063d1e69ee4a7081bc0c5135c9281d [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:11.199234   826 raft_consensus.cc:493] T 00000000000000000000000000000000 P 98063d1e69ee4a7081bc0c5135c9281d [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:11.199388   826 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 98063d1e69ee4a7081bc0c5135c9281d [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:11.200307   826 raft_consensus.cc:515] T 00000000000000000000000000000000 P 98063d1e69ee4a7081bc0c5135c9281d [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "98063d1e69ee4a7081bc0c5135c9281d" member_type: VOTER }
I20260812 06:17:11.200799   826 leader_election.cc:304] T 00000000000000000000000000000000 P 98063d1e69ee4a7081bc0c5135c9281d [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: 98063d1e69ee4a7081bc0c5135c9281d; no voters: 
I20260812 06:17:11.201164   826 leader_election.cc:290] T 00000000000000000000000000000000 P 98063d1e69ee4a7081bc0c5135c9281d [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:11.201297   829 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 98063d1e69ee4a7081bc0c5135c9281d [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:11.201573   829 raft_consensus.cc:697] T 00000000000000000000000000000000 P 98063d1e69ee4a7081bc0c5135c9281d [term 1 LEADER]: Becoming Leader. State: Replica: 98063d1e69ee4a7081bc0c5135c9281d, State: Running, Role: LEADER
I20260812 06:17:11.202059   829 consensus_queue.cc:237] T 00000000000000000000000000000000 P 98063d1e69ee4a7081bc0c5135c9281d [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: "98063d1e69ee4a7081bc0c5135c9281d" member_type: VOTER }
I20260812 06:17:11.202282   826 sys_catalog.cc:565] T 00000000000000000000000000000000 P 98063d1e69ee4a7081bc0c5135c9281d [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:11.204114   832 sys_catalog.cc:455] T 00000000000000000000000000000000 P 98063d1e69ee4a7081bc0c5135c9281d [sys.catalog]: SysCatalogTable state changed. Reason: New leader 98063d1e69ee4a7081bc0c5135c9281d. Latest consensus state: current_term: 1 leader_uuid: "98063d1e69ee4a7081bc0c5135c9281d" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "98063d1e69ee4a7081bc0c5135c9281d" member_type: VOTER } }
I20260812 06:17:11.204162   831 sys_catalog.cc:455] T 00000000000000000000000000000000 P 98063d1e69ee4a7081bc0c5135c9281d [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "98063d1e69ee4a7081bc0c5135c9281d" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "98063d1e69ee4a7081bc0c5135c9281d" member_type: VOTER } }
I20260812 06:17:11.204265   832 sys_catalog.cc:458] T 00000000000000000000000000000000 P 98063d1e69ee4a7081bc0c5135c9281d [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:11.204265   831 sys_catalog.cc:458] T 00000000000000000000000000000000 P 98063d1e69ee4a7081bc0c5135c9281d [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:11.204633   841 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:11.204891   757 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:11.207029   841 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:11.212247   841 catalog_manager.cc:1383] Generated new cluster ID: 82ee3ab7c220473c9fcbc8470bab600d
I20260812 06:17:11.212344   841 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:11.236596   841 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:11.237551   841 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:11.251082   841 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 98063d1e69ee4a7081bc0c5135c9281d: Generated new TSK 0
I20260812 06:17:11.251919   841 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:11.269691   757 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:11.272853   852 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:11.272862   849 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:17:11.273234   850 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:17:11.273272   757 server_base.cc:1061] running on GCE node
I20260812 06:17:11.273579   757 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:11.273654   757 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:11.273684   757 hybrid_clock.cc:648] HybridClock initialized: now 1786515431273683 us; error 0 us; skew 500 ppm
I20260812 06:17:11.274822   757 webserver.cc:533] Webserver started at http://127.0.189.65:43815/ using document root <none> and password file <none>
I20260812 06:17:11.275058   757 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:11.275137   757 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:11.275225   757 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:11.275689   757 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431121259-757-0/minicluster-data/ts-0-root/instance:
uuid: "78fc263d8f564f98a1c196281610c46f"
format_stamp: "Formatted at 2026-08-12 06:17:11 on dist-test-slave-zpfg"
I20260812 06:17:11.277787   757 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.000s	sys 0.003s
I20260812 06:17:11.279022   858 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:11.279462   757 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.000s
I20260812 06:17:11.279544   757 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431121259-757-0/minicluster-data/ts-0-root
uuid: "78fc263d8f564f98a1c196281610c46f"
format_stamp: "Formatted at 2026-08-12 06:17:11 on dist-test-slave-zpfg"
I20260812 06:17:11.279655   757 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431121259-757-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431121259-757-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431121259-757-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:11.295039   757 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:11.295605   757 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:11.296171   757 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:11.297425   757 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:11.297479   757 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:11.297544   757 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:11.297585   757 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:11.304796   757 rpc_server.cc:307] RPC server started. Bound to: 127.0.189.65:39789
I20260812 06:17:11.304877   927 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.0.189.65:39789 every 8 connection(s)
I20260812 06:17:11.315258   928 heartbeater.cc:344] Connected to a master server at 127.0.189.126:33087
I20260812 06:17:11.315596   928 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:11.316093   928 heartbeater.cc:507] Master 127.0.189.126:33087 requested a full tablet report, sending...
I20260812 06:17:11.317660   787 ts_manager.cc:194] Registered new tserver with Master: 78fc263d8f564f98a1c196281610c46f (127.0.189.65:39789)
I20260812 06:17:11.317847   757 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.012377583s
I20260812 06:17:11.319283   787 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:60828
I20260812 06:17:11.328245   787 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:60832:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:17:11.343837   888 tablet_service.cc:1511] Processing CreateTablet for tablet 6840cf69423546c88c3740cdb82e3978 (DEFAULT_TABLE table=heavy-update-compaction-test [id=583d42e76c2246dfb50539d269e05546]), partition=
I20260812 06:17:11.344395   888 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 6840cf69423546c88c3740cdb82e3978. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:11.346998   940 tablet_bootstrap.cc:492] T 6840cf69423546c88c3740cdb82e3978 P 78fc263d8f564f98a1c196281610c46f: Bootstrap starting.
I20260812 06:17:11.348224   940 tablet_bootstrap.cc:654] T 6840cf69423546c88c3740cdb82e3978 P 78fc263d8f564f98a1c196281610c46f: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:11.350003   940 tablet_bootstrap.cc:492] T 6840cf69423546c88c3740cdb82e3978 P 78fc263d8f564f98a1c196281610c46f: No bootstrap required, opened a new log
I20260812 06:17:11.350137   940 ts_tablet_manager.cc:1403] T 6840cf69423546c88c3740cdb82e3978 P 78fc263d8f564f98a1c196281610c46f: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:17:11.350800   940 raft_consensus.cc:359] T 6840cf69423546c88c3740cdb82e3978 P 78fc263d8f564f98a1c196281610c46f [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "78fc263d8f564f98a1c196281610c46f" member_type: VOTER last_known_addr { host: "127.0.189.65" port: 39789 } }
I20260812 06:17:11.350940   940 raft_consensus.cc:385] T 6840cf69423546c88c3740cdb82e3978 P 78fc263d8f564f98a1c196281610c46f [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:11.350996   940 raft_consensus.cc:740] T 6840cf69423546c88c3740cdb82e3978 P 78fc263d8f564f98a1c196281610c46f [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 78fc263d8f564f98a1c196281610c46f, State: Initialized, Role: FOLLOWER
I20260812 06:17:11.351146   940 consensus_queue.cc:260] T 6840cf69423546c88c3740cdb82e3978 P 78fc263d8f564f98a1c196281610c46f [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: "78fc263d8f564f98a1c196281610c46f" member_type: VOTER last_known_addr { host: "127.0.189.65" port: 39789 } }
I20260812 06:17:11.351253   940 raft_consensus.cc:399] T 6840cf69423546c88c3740cdb82e3978 P 78fc263d8f564f98a1c196281610c46f [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:11.351302   940 raft_consensus.cc:493] T 6840cf69423546c88c3740cdb82e3978 P 78fc263d8f564f98a1c196281610c46f [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:11.351356   940 raft_consensus.cc:3060] T 6840cf69423546c88c3740cdb82e3978 P 78fc263d8f564f98a1c196281610c46f [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:11.359283   940 raft_consensus.cc:515] T 6840cf69423546c88c3740cdb82e3978 P 78fc263d8f564f98a1c196281610c46f [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "78fc263d8f564f98a1c196281610c46f" member_type: VOTER last_known_addr { host: "127.0.189.65" port: 39789 } }
I20260812 06:17:11.359512   940 leader_election.cc:304] T 6840cf69423546c88c3740cdb82e3978 P 78fc263d8f564f98a1c196281610c46f [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: 78fc263d8f564f98a1c196281610c46f; no voters: 
I20260812 06:17:11.359830   940 leader_election.cc:290] T 6840cf69423546c88c3740cdb82e3978 P 78fc263d8f564f98a1c196281610c46f [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:11.359992   942 raft_consensus.cc:2804] T 6840cf69423546c88c3740cdb82e3978 P 78fc263d8f564f98a1c196281610c46f [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:11.360388   940 ts_tablet_manager.cc:1434] T 6840cf69423546c88c3740cdb82e3978 P 78fc263d8f564f98a1c196281610c46f: Time spent starting tablet: real 0.010s	user 0.000s	sys 0.004s
I20260812 06:17:11.360505   942 raft_consensus.cc:697] T 6840cf69423546c88c3740cdb82e3978 P 78fc263d8f564f98a1c196281610c46f [term 1 LEADER]: Becoming Leader. State: Replica: 78fc263d8f564f98a1c196281610c46f, State: Running, Role: LEADER
I20260812 06:17:11.360754   928 heartbeater.cc:499] Master 127.0.189.126:33087 was elected leader, sending a full tablet report...
I20260812 06:17:11.360764   942 consensus_queue.cc:237] T 6840cf69423546c88c3740cdb82e3978 P 78fc263d8f564f98a1c196281610c46f [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: "78fc263d8f564f98a1c196281610c46f" member_type: VOTER last_known_addr { host: "127.0.189.65" port: 39789 } }
I20260812 06:17:11.364301   787 catalog_manager.cc:5719] T 6840cf69423546c88c3740cdb82e3978 P 78fc263d8f564f98a1c196281610c46f reported cstate change: term changed from 0 to 1, leader changed from <none> to 78fc263d8f564f98a1c196281610c46f (127.0.189.65). New cstate: current_term: 1 leader_uuid: "78fc263d8f564f98a1c196281610c46f" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "78fc263d8f564f98a1c196281610c46f" member_type: VOTER last_known_addr { host: "127.0.189.65" port: 39789 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:11.427713   757 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.055s	user 0.013s	sys 0.011s
I20260812 06:17:11.556034   929 maintenance_manager.cc:419] P 78fc263d8f564f98a1c196281610c46f: Scheduling FlushMRSOp(6840cf69423546c88c3740cdb82e3978): perf score=15.086190
I20260812 06:17:11.706975   863 maintenance_manager.cc:643] P 78fc263d8f564f98a1c196281610c46f: FlushMRSOp(6840cf69423546c88c3740cdb82e3978) complete. Timing: real 0.150s	user 0.114s	sys 0.028s Metrics: {"bytes_written":8615324,"cfile_init":1,"compiler_manager_pool.queue_time_us":370,"delete_count":0,"dirs.queue_time_us":55,"dirs.run_cpu_time_us":236,"dirs.run_wall_time_us":817,"drs_written":1,"lbm_read_time_us":79,"lbm_reads_lt_1ms":4,"lbm_write_time_us":34009,"lbm_writes_lt_1ms":667,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":150144,"thread_start_us":129,"threads_started":1,"update_count":1050}
I20260812 06:17:11.708003   929 maintenance_manager.cc:419] P 78fc263d8f564f98a1c196281610c46f: Scheduling LogGCOp(6840cf69423546c88c3740cdb82e3978): free 20743880 bytes of WAL
I20260812 06:17:11.708307   863 log_reader.cc:385] T 6840cf69423546c88c3740cdb82e3978: removed 2 log segments from log reader
I20260812 06:17:11.708387   863 log.cc:1079] T 6840cf69423546c88c3740cdb82e3978 P 78fc263d8f564f98a1c196281610c46f: Deleting log segment in path: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431121259-757-0/minicluster-data/ts-0-root/wals/6840cf69423546c88c3740cdb82e3978/wal-000000001 (ops 1-6)
I20260812 06:17:11.708489   863 log.cc:1079] T 6840cf69423546c88c3740cdb82e3978 P 78fc263d8f564f98a1c196281610c46f: Deleting log segment in path: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431121259-757-0/minicluster-data/ts-0-root/wals/6840cf69423546c88c3740cdb82e3978/wal-000000002 (ops 7-11)
I20260812 06:17:11.712666   863 maintenance_manager.cc:643] P 78fc263d8f564f98a1c196281610c46f: LogGCOp(6840cf69423546c88c3740cdb82e3978) complete. Timing: real 0.004s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:17:11.713032   929 maintenance_manager.cc:419] P 78fc263d8f564f98a1c196281610c46f: Scheduling FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978): perf score=2.188937
I20260812 06:17:11.725595   863 maintenance_manager.cc:643] P 78fc263d8f564f98a1c196281610c46f: FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4414,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:11.726099   929 maintenance_manager.cc:419] P 78fc263d8f564f98a1c196281610c46f: Scheduling UndoDeltaBlockGCOp(6840cf69423546c88c3740cdb82e3978): 16411393 bytes on disk
I20260812 06:17:11.726917   863 maintenance_manager.cc:643] P 78fc263d8f564f98a1c196281610c46f: UndoDeltaBlockGCOp(6840cf69423546c88c3740cdb82e3978) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":92,"lbm_reads_lt_1ms":4}
I20260812 06:17:11.727451   929 maintenance_manager.cc:419] P 78fc263d8f564f98a1c196281610c46f: Scheduling MajorDeltaCompactionOp(6840cf69423546c88c3740cdb82e3978): perf score=1.000000
I20260812 06:17:11.835619   863 maintenance_manager.cc:643] P 78fc263d8f564f98a1c196281610c46f: MajorDeltaCompactionOp(6840cf69423546c88c3740cdb82e3978) complete. Timing: real 0.108s	user 0.092s	sys 0.012s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16569857,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":58,"lbm_read_time_us":7506,"lbm_reads_lt_1ms":364,"lbm_write_time_us":18287,"lbm_writes_lt_1ms":343,"mutex_wait_us":23,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":11776,"thread_start_us":342,"threads_started":5,"update_count":1500}
I20260812 06:17:11.836299   929 maintenance_manager.cc:419] P 78fc263d8f564f98a1c196281610c46f: Scheduling FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978): perf score=7.149875
I20260812 06:17:11.860905   863 maintenance_manager.cc:643] P 78fc263d8f564f98a1c196281610c46f: FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978) complete. Timing: real 0.024s	user 0.018s	sys 0.004s Metrics: {"bytes_written":8615323,"delete_count":0,"lbm_write_time_us":10100,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:17:11.861552   929 maintenance_manager.cc:419] P 78fc263d8f564f98a1c196281610c46f: Scheduling FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978): perf score=2.188937
I20260812 06:17:11.876709   863 maintenance_manager.cc:643] P 78fc263d8f564f98a1c196281610c46f: FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978) complete. Timing: real 0.015s	user 0.010s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5772,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:11.877290   929 maintenance_manager.cc:419] P 78fc263d8f564f98a1c196281610c46f: Scheduling MajorDeltaCompactionOp(6840cf69423546c88c3740cdb82e3978): perf score=1.000000
I20260812 06:17:11.997102   863 maintenance_manager.cc:643] P 78fc263d8f564f98a1c196281610c46f: MajorDeltaCompactionOp(6840cf69423546c88c3740cdb82e3978) complete. Timing: real 0.119s	user 0.092s	sys 0.012s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16569856,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1418,"lbm_read_time_us":6210,"lbm_reads_lt_1ms":368,"lbm_write_time_us":20416,"lbm_writes_lt_1ms":343,"mutex_wait_us":410,"peak_mem_usage":38262756,"reinsert_count":0,"update_count":1500}
I20260812 06:17:11.997674   929 maintenance_manager.cc:419] P 78fc263d8f564f98a1c196281610c46f: Scheduling FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978): perf score=10.126437
I20260812 06:17:12.050639   863 maintenance_manager.cc:643] P 78fc263d8f564f98a1c196281610c46f: FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978) complete. Timing: real 0.053s	user 0.039s	sys 0.004s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":18910,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:12.051122   929 maintenance_manager.cc:419] P 78fc263d8f564f98a1c196281610c46f: Scheduling FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978): perf score=2.188937
I20260812 06:17:12.063745   863 maintenance_manager.cc:643] P 78fc263d8f564f98a1c196281610c46f: FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978) complete. Timing: real 0.012s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4489,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:12.064419   929 maintenance_manager.cc:419] P 78fc263d8f564f98a1c196281610c46f: Scheduling MajorDeltaCompactionOp(6840cf69423546c88c3740cdb82e3978): perf score=1.000000
I20260812 06:17:12.201659   863 maintenance_manager.cc:643] P 78fc263d8f564f98a1c196281610c46f: MajorDeltaCompactionOp(6840cf69423546c88c3740cdb82e3978) complete. Timing: real 0.137s	user 0.108s	sys 0.029s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":344,"lbm_read_time_us":8443,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26179,"lbm_writes_lt_1ms":443,"mutex_wait_us":63,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:17:12.202329   929 maintenance_manager.cc:419] P 78fc263d8f564f98a1c196281610c46f: Scheduling FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978): perf score=10.126437
I20260812 06:17:12.238566   863 maintenance_manager.cc:643] P 78fc263d8f564f98a1c196281610c46f: FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978) complete. Timing: real 0.036s	user 0.023s	sys 0.013s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14950,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:12.239204   929 maintenance_manager.cc:419] P 78fc263d8f564f98a1c196281610c46f: Scheduling FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978): perf score=2.188937
I20260812 06:17:12.251348   863 maintenance_manager.cc:643] P 78fc263d8f564f98a1c196281610c46f: FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4245,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:12.252035   929 maintenance_manager.cc:419] P 78fc263d8f564f98a1c196281610c46f: Scheduling MajorDeltaCompactionOp(6840cf69423546c88c3740cdb82e3978): perf score=1.000000
I20260812 06:17:12.385964   863 maintenance_manager.cc:643] P 78fc263d8f564f98a1c196281610c46f: MajorDeltaCompactionOp(6840cf69423546c88c3740cdb82e3978) complete. Timing: real 0.134s	user 0.093s	sys 0.040s 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":1341,"lbm_read_time_us":8750,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25855,"lbm_writes_lt_1ms":443,"mutex_wait_us":361,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":22784,"update_count":2000}
I20260812 06:17:12.386770   929 maintenance_manager.cc:419] P 78fc263d8f564f98a1c196281610c46f: Scheduling FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978): perf score=10.126437
I20260812 06:17:12.427850   863 maintenance_manager.cc:643] P 78fc263d8f564f98a1c196281610c46f: FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978) complete. Timing: real 0.041s	user 0.023s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15128,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:12.428309   929 maintenance_manager.cc:419] P 78fc263d8f564f98a1c196281610c46f: Scheduling FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978): perf score=2.188937
I20260812 06:17:12.439026   863 maintenance_manager.cc:643] P 78fc263d8f564f98a1c196281610c46f: FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4032,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:12.439674   929 maintenance_manager.cc:419] P 78fc263d8f564f98a1c196281610c46f: Scheduling MajorDeltaCompactionOp(6840cf69423546c88c3740cdb82e3978): perf score=1.000000
I20260812 06:17:12.569387   863 maintenance_manager.cc:643] P 78fc263d8f564f98a1c196281610c46f: MajorDeltaCompactionOp(6840cf69423546c88c3740cdb82e3978) complete. Timing: real 0.130s	user 0.105s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":700,"lbm_read_time_us":8629,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25861,"lbm_writes_lt_1ms":443,"mutex_wait_us":50,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":22656,"update_count":2000}
I20260812 06:17:12.570075   929 maintenance_manager.cc:419] P 78fc263d8f564f98a1c196281610c46f: Scheduling FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978): perf score=10.126437
I20260812 06:17:12.617098   863 maintenance_manager.cc:643] P 78fc263d8f564f98a1c196281610c46f: FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978) complete. Timing: real 0.047s	user 0.023s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14846,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:12.617692   929 maintenance_manager.cc:419] P 78fc263d8f564f98a1c196281610c46f: Scheduling FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978): perf score=2.188937
I20260812 06:17:12.628768   863 maintenance_manager.cc:643] P 78fc263d8f564f98a1c196281610c46f: FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4312,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:12.629228   929 maintenance_manager.cc:419] P 78fc263d8f564f98a1c196281610c46f: Scheduling MajorDeltaCompactionOp(6840cf69423546c88c3740cdb82e3978): perf score=1.000000
I20260812 06:17:12.784144   863 maintenance_manager.cc:643] P 78fc263d8f564f98a1c196281610c46f: MajorDeltaCompactionOp(6840cf69423546c88c3740cdb82e3978) complete. Timing: real 0.155s	user 0.095s	sys 0.048s 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":1082,"lbm_read_time_us":11016,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21697,"lbm_writes_lt_1ms":443,"mutex_wait_us":159,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11520,"update_count":2000}
I20260812 06:17:12.784880   929 maintenance_manager.cc:419] P 78fc263d8f564f98a1c196281610c46f: Scheduling FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978): perf score=10.126437
I20260812 06:17:12.830060   863 maintenance_manager.cc:643] P 78fc263d8f564f98a1c196281610c46f: FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978) complete. Timing: real 0.045s	user 0.023s	sys 0.015s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":17026,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:17:12.830622   929 maintenance_manager.cc:419] P 78fc263d8f564f98a1c196281610c46f: Scheduling FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978): perf score=2.188937
I20260812 06:17:12.844275   863 maintenance_manager.cc:643] P 78fc263d8f564f98a1c196281610c46f: FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978) complete. Timing: real 0.013s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4644,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:12.844796   929 maintenance_manager.cc:419] P 78fc263d8f564f98a1c196281610c46f: Scheduling MajorDeltaCompactionOp(6840cf69423546c88c3740cdb82e3978): perf score=1.000000
I20260812 06:17:12.986784   863 maintenance_manager.cc:643] P 78fc263d8f564f98a1c196281610c46f: MajorDeltaCompactionOp(6840cf69423546c88c3740cdb82e3978) complete. Timing: real 0.142s	user 0.119s	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":1569,"lbm_read_time_us":9143,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28322,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:17:12.987337   929 maintenance_manager.cc:419] P 78fc263d8f564f98a1c196281610c46f: Scheduling FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978): perf score=11.118625
I20260812 06:17:13.025461   863 maintenance_manager.cc:643] P 78fc263d8f564f98a1c196281610c46f: FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978) complete. Timing: real 0.038s	user 0.029s	sys 0.005s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":16476,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:13.026139   929 maintenance_manager.cc:419] P 78fc263d8f564f98a1c196281610c46f: Scheduling FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978): perf score=2.188937
I20260812 06:17:13.051842   863 maintenance_manager.cc:643] P 78fc263d8f564f98a1c196281610c46f: FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978) complete. Timing: real 0.026s	user 0.007s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4473,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:13.052438   929 maintenance_manager.cc:419] P 78fc263d8f564f98a1c196281610c46f: Scheduling FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978): perf score=2.188937
I20260812 06:17:13.063943   863 maintenance_manager.cc:643] P 78fc263d8f564f98a1c196281610c46f: FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978) complete. Timing: real 0.011s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4222,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:13.064447   929 maintenance_manager.cc:419] P 78fc263d8f564f98a1c196281610c46f: Scheduling FlushMRSOp(6840cf69423546c88c3740cdb82e3978): perf score=1.000000
I20260812 06:17:13.096408   863 maintenance_manager.cc:643] P 78fc263d8f564f98a1c196281610c46f: FlushMRSOp(6840cf69423546c88c3740cdb82e3978) complete. Timing: real 0.032s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1275443,"cfile_init":1,"dirs.queue_time_us":106,"dirs.run_cpu_time_us":294,"dirs.run_wall_time_us":1537,"drs_written":1,"lbm_read_time_us":41,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1743,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:17:13.097368   929 maintenance_manager.cc:419] P 78fc263d8f564f98a1c196281610c46f: Scheduling LogGCOp(6840cf69423546c88c3740cdb82e3978): free 124710298 bytes of WAL
I20260812 06:17:13.097652   863 log_reader.cc:385] T 6840cf69423546c88c3740cdb82e3978: removed 12 log segments from log reader
I20260812 06:17:13.097721   863 log.cc:1079] T 6840cf69423546c88c3740cdb82e3978 P 78fc263d8f564f98a1c196281610c46f: Deleting log segment in path: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431121259-757-0/minicluster-data/ts-0-root/wals/6840cf69423546c88c3740cdb82e3978/wal-000000003 (ops 12-16)
I20260812 06:17:13.097761   863 log.cc:1079] T 6840cf69423546c88c3740cdb82e3978 P 78fc263d8f564f98a1c196281610c46f: Deleting log segment in path: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431121259-757-0/minicluster-data/ts-0-root/wals/6840cf69423546c88c3740cdb82e3978/wal-000000004 (ops 17-21)
I20260812 06:17:13.097792   863 log.cc:1079] T 6840cf69423546c88c3740cdb82e3978 P 78fc263d8f564f98a1c196281610c46f: Deleting log segment in path: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431121259-757-0/minicluster-data/ts-0-root/wals/6840cf69423546c88c3740cdb82e3978/wal-000000005 (ops 22-26)
I20260812 06:17:13.097819   863 log.cc:1079] T 6840cf69423546c88c3740cdb82e3978 P 78fc263d8f564f98a1c196281610c46f: Deleting log segment in path: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431121259-757-0/minicluster-data/ts-0-root/wals/6840cf69423546c88c3740cdb82e3978/wal-000000006 (ops 27-31)
I20260812 06:17:13.097853   863 log.cc:1079] T 6840cf69423546c88c3740cdb82e3978 P 78fc263d8f564f98a1c196281610c46f: Deleting log segment in path: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431121259-757-0/minicluster-data/ts-0-root/wals/6840cf69423546c88c3740cdb82e3978/wal-000000007 (ops 32-36)
I20260812 06:17:13.097882   863 log.cc:1079] T 6840cf69423546c88c3740cdb82e3978 P 78fc263d8f564f98a1c196281610c46f: Deleting log segment in path: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431121259-757-0/minicluster-data/ts-0-root/wals/6840cf69423546c88c3740cdb82e3978/wal-000000008 (ops 37-41)
I20260812 06:17:13.097913   863 log.cc:1079] T 6840cf69423546c88c3740cdb82e3978 P 78fc263d8f564f98a1c196281610c46f: Deleting log segment in path: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431121259-757-0/minicluster-data/ts-0-root/wals/6840cf69423546c88c3740cdb82e3978/wal-000000009 (ops 42-46)
I20260812 06:17:13.097942   863 log.cc:1079] T 6840cf69423546c88c3740cdb82e3978 P 78fc263d8f564f98a1c196281610c46f: Deleting log segment in path: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431121259-757-0/minicluster-data/ts-0-root/wals/6840cf69423546c88c3740cdb82e3978/wal-000000010 (ops 47-51)
I20260812 06:17:13.097973   863 log.cc:1079] T 6840cf69423546c88c3740cdb82e3978 P 78fc263d8f564f98a1c196281610c46f: Deleting log segment in path: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431121259-757-0/minicluster-data/ts-0-root/wals/6840cf69423546c88c3740cdb82e3978/wal-000000011 (ops 52-56)
I20260812 06:17:13.098007   863 log.cc:1079] T 6840cf69423546c88c3740cdb82e3978 P 78fc263d8f564f98a1c196281610c46f: Deleting log segment in path: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431121259-757-0/minicluster-data/ts-0-root/wals/6840cf69423546c88c3740cdb82e3978/wal-000000012 (ops 57-61)
I20260812 06:17:13.098037   863 log.cc:1079] T 6840cf69423546c88c3740cdb82e3978 P 78fc263d8f564f98a1c196281610c46f: Deleting log segment in path: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431121259-757-0/minicluster-data/ts-0-root/wals/6840cf69423546c88c3740cdb82e3978/wal-000000013 (ops 62-66)
I20260812 06:17:13.098067   863 log.cc:1079] T 6840cf69423546c88c3740cdb82e3978 P 78fc263d8f564f98a1c196281610c46f: Deleting log segment in path: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431121259-757-0/minicluster-data/ts-0-root/wals/6840cf69423546c88c3740cdb82e3978/wal-000000014 (ops 67-71)
I20260812 06:17:13.129696   863 maintenance_manager.cc:643] P 78fc263d8f564f98a1c196281610c46f: LogGCOp(6840cf69423546c88c3740cdb82e3978) complete. Timing: real 0.032s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:17:13.130216   929 maintenance_manager.cc:419] P 78fc263d8f564f98a1c196281610c46f: Scheduling UndoDeltaBlockGCOp(6840cf69423546c88c3740cdb82e3978): 483 bytes on disk
I20260812 06:17:13.130918   863 maintenance_manager.cc:643] P 78fc263d8f564f98a1c196281610c46f: UndoDeltaBlockGCOp(6840cf69423546c88c3740cdb82e3978) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":98,"lbm_reads_lt_1ms":4}
I20260812 06:17:13.131636   929 maintenance_manager.cc:419] P 78fc263d8f564f98a1c196281610c46f: Scheduling FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978): perf score=2.188937
I20260812 06:17:13.153215   863 maintenance_manager.cc:643] P 78fc263d8f564f98a1c196281610c46f: FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978) complete. Timing: real 0.021s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4458,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:13.153748   929 maintenance_manager.cc:419] P 78fc263d8f564f98a1c196281610c46f: Scheduling FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978): perf score=2.188937
I20260812 06:17:13.164508   863 maintenance_manager.cc:643] P 78fc263d8f564f98a1c196281610c46f: FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4152,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:13.164971   929 maintenance_manager.cc:419] P 78fc263d8f564f98a1c196281610c46f: Scheduling MajorDeltaCompactionOp(6840cf69423546c88c3740cdb82e3978): perf score=1.000000
I20260812 06:17:13.357788   863 maintenance_manager.cc:643] P 78fc263d8f564f98a1c196281610c46f: MajorDeltaCompactionOp(6840cf69423546c88c3740cdb82e3978) complete. Timing: real 0.193s	user 0.151s	sys 0.040s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32979862,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":2236,"lbm_read_time_us":12120,"lbm_reads_lt_1ms":775,"lbm_write_time_us":39175,"lbm_writes_lt_1ms":743,"mutex_wait_us":891,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":6656,"thread_start_us":94,"threads_started":1,"update_count":3500}
I20260812 06:17:13.358847   929 maintenance_manager.cc:419] P 78fc263d8f564f98a1c196281610c46f: Scheduling FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978): perf score=14.095187
I20260812 06:17:13.411192   863 maintenance_manager.cc:643] P 78fc263d8f564f98a1c196281610c46f: FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978) complete. Timing: real 0.052s	user 0.030s	sys 0.020s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":23460,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:13.411743   929 maintenance_manager.cc:419] P 78fc263d8f564f98a1c196281610c46f: Scheduling FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978): perf score=2.188937
I20260812 06:17:13.424834   863 maintenance_manager.cc:643] P 78fc263d8f564f98a1c196281610c46f: FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978) complete. Timing: real 0.013s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4649,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:13.425541   929 maintenance_manager.cc:419] P 78fc263d8f564f98a1c196281610c46f: Scheduling MajorDeltaCompactionOp(6840cf69423546c88c3740cdb82e3978): perf score=1.000000
I20260812 06:17:13.616647   863 maintenance_manager.cc:643] P 78fc263d8f564f98a1c196281610c46f: MajorDeltaCompactionOp(6840cf69423546c88c3740cdb82e3978) complete. Timing: real 0.191s	user 0.133s	sys 0.051s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":525,"lbm_read_time_us":13873,"lbm_reads_lt_1ms":564,"lbm_write_time_us":30165,"lbm_writes_lt_1ms":543,"mutex_wait_us":98,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3200,"update_count":2500}
I20260812 06:17:13.617421   929 maintenance_manager.cc:419] P 78fc263d8f564f98a1c196281610c46f: Scheduling FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978): perf score=14.095187
I20260812 06:17:13.675223   863 maintenance_manager.cc:643] P 78fc263d8f564f98a1c196281610c46f: FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978) complete. Timing: real 0.058s	user 0.030s	sys 0.020s Metrics: {"bytes_written":16409897,"delete_count":0,"lbm_write_time_us":22777,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:13.675736   929 maintenance_manager.cc:419] P 78fc263d8f564f98a1c196281610c46f: Scheduling FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978): perf score=2.188937
I20260812 06:17:13.686816   863 maintenance_manager.cc:643] P 78fc263d8f564f98a1c196281610c46f: FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4163,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:13.687436   929 maintenance_manager.cc:419] P 78fc263d8f564f98a1c196281610c46f: Scheduling MajorDeltaCompactionOp(6840cf69423546c88c3740cdb82e3978): perf score=1.000000
I20260812 06:17:13.864814   863 maintenance_manager.cc:643] P 78fc263d8f564f98a1c196281610c46f: MajorDeltaCompactionOp(6840cf69423546c88c3740cdb82e3978) complete. Timing: real 0.177s	user 0.099s	sys 0.068s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":180,"lbm_read_time_us":11112,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34754,"lbm_writes_lt_1ms":543,"mutex_wait_us":57,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":17280,"update_count":2500}
I20260812 06:17:13.865309   929 maintenance_manager.cc:419] P 78fc263d8f564f98a1c196281610c46f: Scheduling FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978): perf score=14.095187
I20260812 06:17:13.921510   863 maintenance_manager.cc:643] P 78fc263d8f564f98a1c196281610c46f: FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978) complete. Timing: real 0.056s	user 0.018s	sys 0.028s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":24387,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"mutex_wait_us":2,"reinsert_count":0,"update_count":2000}
I20260812 06:17:13.922004   929 maintenance_manager.cc:419] P 78fc263d8f564f98a1c196281610c46f: Scheduling FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978): perf score=2.188937
I20260812 06:17:13.934026   863 maintenance_manager.cc:643] P 78fc263d8f564f98a1c196281610c46f: FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978) complete. Timing: real 0.012s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4289,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:13.934608   929 maintenance_manager.cc:419] P 78fc263d8f564f98a1c196281610c46f: Scheduling MajorDeltaCompactionOp(6840cf69423546c88c3740cdb82e3978): perf score=1.000000
I20260812 06:17:14.087423   863 maintenance_manager.cc:643] P 78fc263d8f564f98a1c196281610c46f: MajorDeltaCompactionOp(6840cf69423546c88c3740cdb82e3978) complete. Timing: real 0.153s	user 0.111s	sys 0.032s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1005,"lbm_read_time_us":9906,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30407,"lbm_writes_lt_1ms":543,"mutex_wait_us":314,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2816,"update_count":2500}
I20260812 06:17:14.088099   929 maintenance_manager.cc:419] P 78fc263d8f564f98a1c196281610c46f: Scheduling FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978): perf score=14.095187
I20260812 06:17:14.137761   863 maintenance_manager.cc:643] P 78fc263d8f564f98a1c196281610c46f: FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978) complete. Timing: real 0.049s	user 0.021s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21674,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:14.138311   929 maintenance_manager.cc:419] P 78fc263d8f564f98a1c196281610c46f: Scheduling FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978): perf score=2.188937
I20260812 06:17:14.150287   863 maintenance_manager.cc:643] P 78fc263d8f564f98a1c196281610c46f: FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978) complete. Timing: real 0.012s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4318,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:14.150828   929 maintenance_manager.cc:419] P 78fc263d8f564f98a1c196281610c46f: Scheduling MajorDeltaCompactionOp(6840cf69423546c88c3740cdb82e3978): perf score=1.000000
I20260812 06:17:14.317093   863 maintenance_manager.cc:643] P 78fc263d8f564f98a1c196281610c46f: MajorDeltaCompactionOp(6840cf69423546c88c3740cdb82e3978) complete. Timing: real 0.166s	user 0.125s	sys 0.032s 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":832,"lbm_read_time_us":10335,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33005,"lbm_writes_lt_1ms":543,"mutex_wait_us":332,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:17:14.317847   929 maintenance_manager.cc:419] P 78fc263d8f564f98a1c196281610c46f: Scheduling FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978): perf score=14.095187
I20260812 06:17:14.377300   863 maintenance_manager.cc:643] P 78fc263d8f564f98a1c196281610c46f: FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978) complete. Timing: real 0.059s	user 0.037s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24930,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:14.377827   929 maintenance_manager.cc:419] P 78fc263d8f564f98a1c196281610c46f: Scheduling FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978): perf score=2.188937
I20260812 06:17:14.391196   863 maintenance_manager.cc:643] P 78fc263d8f564f98a1c196281610c46f: FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978) complete. Timing: real 0.013s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4366,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:14.391811   929 maintenance_manager.cc:419] P 78fc263d8f564f98a1c196281610c46f: Scheduling MajorDeltaCompactionOp(6840cf69423546c88c3740cdb82e3978): perf score=1.000000
I20260812 06:17:14.542575   863 maintenance_manager.cc:643] P 78fc263d8f564f98a1c196281610c46f: MajorDeltaCompactionOp(6840cf69423546c88c3740cdb82e3978) complete. Timing: real 0.151s	user 0.104s	sys 0.043s 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":585,"lbm_read_time_us":9447,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30361,"lbm_writes_lt_1ms":543,"mutex_wait_us":56,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11648,"update_count":2500}
I20260812 06:17:14.543555   929 maintenance_manager.cc:419] P 78fc263d8f564f98a1c196281610c46f: Scheduling FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978): perf score=10.126437
I20260812 06:17:14.585810   863 maintenance_manager.cc:643] P 78fc263d8f564f98a1c196281610c46f: FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978) complete. Timing: real 0.042s	user 0.018s	sys 0.017s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16261,"lbm_writes_lt_1ms":303,"reinsert_count":0,"spinlock_wait_cycles":2944,"update_count":1500}
I20260812 06:17:14.586443   929 maintenance_manager.cc:419] P 78fc263d8f564f98a1c196281610c46f: Scheduling FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978): perf score=2.188937
I20260812 06:17:14.597401   863 maintenance_manager.cc:643] P 78fc263d8f564f98a1c196281610c46f: FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4320,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:14.597918   929 maintenance_manager.cc:419] P 78fc263d8f564f98a1c196281610c46f: Scheduling FlushMRSOp(6840cf69423546c88c3740cdb82e3978): perf score=1.000000
I20260812 06:17:14.628356   863 maintenance_manager.cc:643] P 78fc263d8f564f98a1c196281610c46f: FlushMRSOp(6840cf69423546c88c3740cdb82e3978) complete. Timing: real 0.030s	user 0.026s	sys 0.003s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":70,"dirs.run_cpu_time_us":250,"dirs.run_wall_time_us":1593,"drs_written":1,"lbm_read_time_us":67,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1770,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31,"spinlock_wait_cycles":896}
I20260812 06:17:14.629196   929 maintenance_manager.cc:419] P 78fc263d8f564f98a1c196281610c46f: Scheduling LogGCOp(6840cf69423546c88c3740cdb82e3978): free 124710310 bytes of WAL
I20260812 06:17:14.629503   863 log_reader.cc:385] T 6840cf69423546c88c3740cdb82e3978: removed 12 log segments from log reader
I20260812 06:17:14.629580   863 log.cc:1079] T 6840cf69423546c88c3740cdb82e3978 P 78fc263d8f564f98a1c196281610c46f: Deleting log segment in path: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431121259-757-0/minicluster-data/ts-0-root/wals/6840cf69423546c88c3740cdb82e3978/wal-000000015 (ops 72-76)
I20260812 06:17:14.629634   863 log.cc:1079] T 6840cf69423546c88c3740cdb82e3978 P 78fc263d8f564f98a1c196281610c46f: Deleting log segment in path: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431121259-757-0/minicluster-data/ts-0-root/wals/6840cf69423546c88c3740cdb82e3978/wal-000000016 (ops 77-81)
I20260812 06:17:14.629709   863 log.cc:1079] T 6840cf69423546c88c3740cdb82e3978 P 78fc263d8f564f98a1c196281610c46f: Deleting log segment in path: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431121259-757-0/minicluster-data/ts-0-root/wals/6840cf69423546c88c3740cdb82e3978/wal-000000017 (ops 82-86)
I20260812 06:17:14.629750   863 log.cc:1079] T 6840cf69423546c88c3740cdb82e3978 P 78fc263d8f564f98a1c196281610c46f: Deleting log segment in path: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431121259-757-0/minicluster-data/ts-0-root/wals/6840cf69423546c88c3740cdb82e3978/wal-000000018 (ops 87-91)
I20260812 06:17:14.629801   863 log.cc:1079] T 6840cf69423546c88c3740cdb82e3978 P 78fc263d8f564f98a1c196281610c46f: Deleting log segment in path: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431121259-757-0/minicluster-data/ts-0-root/wals/6840cf69423546c88c3740cdb82e3978/wal-000000019 (ops 92-96)
I20260812 06:17:14.629845   863 log.cc:1079] T 6840cf69423546c88c3740cdb82e3978 P 78fc263d8f564f98a1c196281610c46f: Deleting log segment in path: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431121259-757-0/minicluster-data/ts-0-root/wals/6840cf69423546c88c3740cdb82e3978/wal-000000020 (ops 97-101)
I20260812 06:17:14.629882   863 log.cc:1079] T 6840cf69423546c88c3740cdb82e3978 P 78fc263d8f564f98a1c196281610c46f: Deleting log segment in path: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431121259-757-0/minicluster-data/ts-0-root/wals/6840cf69423546c88c3740cdb82e3978/wal-000000021 (ops 102-106)
I20260812 06:17:14.629920   863 log.cc:1079] T 6840cf69423546c88c3740cdb82e3978 P 78fc263d8f564f98a1c196281610c46f: Deleting log segment in path: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431121259-757-0/minicluster-data/ts-0-root/wals/6840cf69423546c88c3740cdb82e3978/wal-000000022 (ops 107-111)
I20260812 06:17:14.629956   863 log.cc:1079] T 6840cf69423546c88c3740cdb82e3978 P 78fc263d8f564f98a1c196281610c46f: Deleting log segment in path: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431121259-757-0/minicluster-data/ts-0-root/wals/6840cf69423546c88c3740cdb82e3978/wal-000000023 (ops 112-116)
I20260812 06:17:14.629998   863 log.cc:1079] T 6840cf69423546c88c3740cdb82e3978 P 78fc263d8f564f98a1c196281610c46f: Deleting log segment in path: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431121259-757-0/minicluster-data/ts-0-root/wals/6840cf69423546c88c3740cdb82e3978/wal-000000024 (ops 117-121)
I20260812 06:17:14.630035   863 log.cc:1079] T 6840cf69423546c88c3740cdb82e3978 P 78fc263d8f564f98a1c196281610c46f: Deleting log segment in path: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431121259-757-0/minicluster-data/ts-0-root/wals/6840cf69423546c88c3740cdb82e3978/wal-000000025 (ops 122-126)
I20260812 06:17:14.630071   863 log.cc:1079] T 6840cf69423546c88c3740cdb82e3978 P 78fc263d8f564f98a1c196281610c46f: Deleting log segment in path: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431121259-757-0/minicluster-data/ts-0-root/wals/6840cf69423546c88c3740cdb82e3978/wal-000000026 (ops 127-131)
I20260812 06:17:14.656090   863 maintenance_manager.cc:643] P 78fc263d8f564f98a1c196281610c46f: LogGCOp(6840cf69423546c88c3740cdb82e3978) complete. Timing: real 0.027s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:17:14.656738   929 maintenance_manager.cc:419] P 78fc263d8f564f98a1c196281610c46f: Scheduling FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978): perf score=3.181125
I20260812 06:17:14.669014   863 maintenance_manager.cc:643] P 78fc263d8f564f98a1c196281610c46f: FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4657,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:14.669524   929 maintenance_manager.cc:419] P 78fc263d8f564f98a1c196281610c46f: Scheduling LogGCOp(6840cf69423546c88c3740cdb82e3978): free 12017954 bytes of WAL
I20260812 06:17:14.669754   863 log_reader.cc:385] T 6840cf69423546c88c3740cdb82e3978: removed 1 log segments from log reader
I20260812 06:17:14.669826   863 log.cc:1079] T 6840cf69423546c88c3740cdb82e3978 P 78fc263d8f564f98a1c196281610c46f: Deleting log segment in path: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431121259-757-0/minicluster-data/ts-0-root/wals/6840cf69423546c88c3740cdb82e3978/wal-000000027 (ops 132-136)
I20260812 06:17:14.672132   863 maintenance_manager.cc:643] P 78fc263d8f564f98a1c196281610c46f: LogGCOp(6840cf69423546c88c3740cdb82e3978) complete. Timing: real 0.002s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:17:14.672482   929 maintenance_manager.cc:419] P 78fc263d8f564f98a1c196281610c46f: Scheduling FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978): perf score=2.188937
I20260812 06:17:14.683449   863 maintenance_manager.cc:643] P 78fc263d8f564f98a1c196281610c46f: FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978) complete. Timing: real 0.011s	user 0.009s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3559,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:14.683972   929 maintenance_manager.cc:419] P 78fc263d8f564f98a1c196281610c46f: Scheduling UndoDeltaBlockGCOp(6840cf69423546c88c3740cdb82e3978): 482 bytes on disk
I20260812 06:17:14.684648   863 maintenance_manager.cc:643] P 78fc263d8f564f98a1c196281610c46f: UndoDeltaBlockGCOp(6840cf69423546c88c3740cdb82e3978) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":98,"lbm_reads_lt_1ms":4}
I20260812 06:17:14.685392   929 maintenance_manager.cc:419] P 78fc263d8f564f98a1c196281610c46f: Scheduling MajorDeltaCompactionOp(6840cf69423546c88c3740cdb82e3978): perf score=1.000000
I20260812 06:17:14.876487   863 maintenance_manager.cc:643] P 78fc263d8f564f98a1c196281610c46f: MajorDeltaCompactionOp(6840cf69423546c88c3740cdb82e3978) complete. Timing: real 0.191s	user 0.139s	sys 0.052s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877329,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":261,"lbm_read_time_us":15439,"lbm_reads_lt_1ms":674,"lbm_write_time_us":31730,"lbm_writes_lt_1ms":643,"mutex_wait_us":40,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2304,"thread_start_us":81,"threads_started":1,"update_count":3000}
I20260812 06:17:14.878780   929 maintenance_manager.cc:419] P 78fc263d8f564f98a1c196281610c46f: Scheduling FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978): perf score=14.095187
I20260812 06:17:14.926764   863 maintenance_manager.cc:643] P 78fc263d8f564f98a1c196281610c46f: FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978) complete. Timing: real 0.048s	user 0.030s	sys 0.017s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20835,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:14.927299   929 maintenance_manager.cc:419] P 78fc263d8f564f98a1c196281610c46f: Scheduling FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978): perf score=2.188937
I20260812 06:17:14.943914   863 maintenance_manager.cc:643] P 78fc263d8f564f98a1c196281610c46f: FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978) complete. Timing: real 0.016s	user 0.002s	sys 0.013s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6526,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:14.944514   929 maintenance_manager.cc:419] P 78fc263d8f564f98a1c196281610c46f: Scheduling MajorDeltaCompactionOp(6840cf69423546c88c3740cdb82e3978): perf score=1.000000
I20260812 06:17:15.114568   863 maintenance_manager.cc:643] P 78fc263d8f564f98a1c196281610c46f: MajorDeltaCompactionOp(6840cf69423546c88c3740cdb82e3978) complete. Timing: real 0.170s	user 0.130s	sys 0.028s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":262,"lbm_read_time_us":10249,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31268,"lbm_writes_lt_1ms":543,"mutex_wait_us":93,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:17:15.115372   929 maintenance_manager.cc:419] P 78fc263d8f564f98a1c196281610c46f: Scheduling FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978): perf score=14.095187
I20260812 06:17:15.158849   863 maintenance_manager.cc:643] P 78fc263d8f564f98a1c196281610c46f: FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978) complete. Timing: real 0.043s	user 0.027s	sys 0.016s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":19584,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:15.159489   929 maintenance_manager.cc:419] P 78fc263d8f564f98a1c196281610c46f: Scheduling MajorDeltaCompactionOp(6840cf69423546c88c3740cdb82e3978): perf score=1.000000
I20260812 06:17:15.317598   863 maintenance_manager.cc:643] P 78fc263d8f564f98a1c196281610c46f: MajorDeltaCompactionOp(6840cf69423546c88c3740cdb82e3978) complete. Timing: real 0.158s	user 0.131s	sys 0.025s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672160,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":215,"lbm_read_time_us":9598,"lbm_reads_lt_1ms":467,"lbm_write_time_us":26792,"lbm_writes_lt_1ms":443,"mutex_wait_us":55,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":69120,"update_count":2000}
I20260812 06:17:15.318243   929 maintenance_manager.cc:419] P 78fc263d8f564f98a1c196281610c46f: Scheduling FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978): perf score=11.118625
I20260812 06:17:15.365324   863 maintenance_manager.cc:643] P 78fc263d8f564f98a1c196281610c46f: FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978) complete. Timing: real 0.047s	user 0.031s	sys 0.013s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":20380,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:15.365928   929 maintenance_manager.cc:419] P 78fc263d8f564f98a1c196281610c46f: Scheduling FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978): perf score=2.188937
I20260812 06:17:15.395386   863 maintenance_manager.cc:643] P 78fc263d8f564f98a1c196281610c46f: FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978) complete. Timing: real 0.029s	user 0.011s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6448,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:15.395922   929 maintenance_manager.cc:419] P 78fc263d8f564f98a1c196281610c46f: Scheduling FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978): perf score=2.188937
I20260812 06:17:15.411885   863 maintenance_manager.cc:643] P 78fc263d8f564f98a1c196281610c46f: FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978) complete. Timing: real 0.016s	user 0.013s	sys 0.002s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6136,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:15.412446   929 maintenance_manager.cc:419] P 78fc263d8f564f98a1c196281610c46f: Scheduling MajorDeltaCompactionOp(6840cf69423546c88c3740cdb82e3978): perf score=1.000000
I20260812 06:17:15.596930   863 maintenance_manager.cc:643] P 78fc263d8f564f98a1c196281610c46f: MajorDeltaCompactionOp(6840cf69423546c88c3740cdb82e3978) complete. Timing: real 0.184s	user 0.104s	sys 0.080s 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":1478,"lbm_read_time_us":13857,"lbm_reads_lt_1ms":573,"lbm_write_time_us":29708,"lbm_writes_lt_1ms":543,"mutex_wait_us":324,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2432,"update_count":2500}
I20260812 06:17:15.597654   929 maintenance_manager.cc:419] P 78fc263d8f564f98a1c196281610c46f: Scheduling FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978): perf score=14.095187
I20260812 06:17:15.653318   863 maintenance_manager.cc:643] P 78fc263d8f564f98a1c196281610c46f: FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978) complete. Timing: real 0.055s	user 0.029s	sys 0.023s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":24027,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:15.653978   929 maintenance_manager.cc:419] P 78fc263d8f564f98a1c196281610c46f: Scheduling FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978): perf score=2.188937
I20260812 06:17:15.676697   863 maintenance_manager.cc:643] P 78fc263d8f564f98a1c196281610c46f: FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978) complete. Timing: real 0.023s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4869,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:15.677182   929 maintenance_manager.cc:419] P 78fc263d8f564f98a1c196281610c46f: Scheduling FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978): perf score=2.188937
I20260812 06:17:15.698939   863 maintenance_manager.cc:643] P 78fc263d8f564f98a1c196281610c46f: FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978) complete. Timing: real 0.022s	user 0.010s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4263,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:15.699627   929 maintenance_manager.cc:419] P 78fc263d8f564f98a1c196281610c46f: Scheduling MajorDeltaCompactionOp(6840cf69423546c88c3740cdb82e3978): perf score=1.000000
I20260812 06:17:15.918560   863 maintenance_manager.cc:643] P 78fc263d8f564f98a1c196281610c46f: MajorDeltaCompactionOp(6840cf69423546c88c3740cdb82e3978) complete. Timing: real 0.219s	user 0.159s	sys 0.056s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877222,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":414,"lbm_read_time_us":14387,"lbm_reads_lt_1ms":673,"lbm_write_time_us":36143,"lbm_writes_lt_1ms":643,"mutex_wait_us":47,"peak_mem_usage":75542472,"reinsert_count":0,"update_count":3000}
I20260812 06:17:15.919415   929 maintenance_manager.cc:419] P 78fc263d8f564f98a1c196281610c46f: Scheduling FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978): perf score=14.095187
I20260812 06:17:15.984091   863 maintenance_manager.cc:643] P 78fc263d8f564f98a1c196281610c46f: FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978) complete. Timing: real 0.064s	user 0.031s	sys 0.031s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":23500,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:15.984843   929 maintenance_manager.cc:419] P 78fc263d8f564f98a1c196281610c46f: Scheduling FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978): perf score=2.188937
I20260812 06:17:15.997341   863 maintenance_manager.cc:643] P 78fc263d8f564f98a1c196281610c46f: FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4693,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:15.997871   929 maintenance_manager.cc:419] P 78fc263d8f564f98a1c196281610c46f: Scheduling MajorDeltaCompactionOp(6840cf69423546c88c3740cdb82e3978): perf score=1.000000
I20260812 06:17:16.184533   863 maintenance_manager.cc:643] P 78fc263d8f564f98a1c196281610c46f: MajorDeltaCompactionOp(6840cf69423546c88c3740cdb82e3978) complete. Timing: real 0.186s	user 0.129s	sys 0.055s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":605,"lbm_read_time_us":14447,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31033,"lbm_writes_lt_1ms":543,"mutex_wait_us":31,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4736,"update_count":2500}
I20260812 06:17:16.185642   929 maintenance_manager.cc:419] P 78fc263d8f564f98a1c196281610c46f: Scheduling FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978): perf score=10.126437
I20260812 06:17:16.227063   863 maintenance_manager.cc:643] P 78fc263d8f564f98a1c196281610c46f: FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978) complete. Timing: real 0.041s	user 0.037s	sys 0.003s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18290,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:16.227741   929 maintenance_manager.cc:419] P 78fc263d8f564f98a1c196281610c46f: Scheduling FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978): perf score=2.188937
I20260812 06:17:16.238831   863 maintenance_manager.cc:643] P 78fc263d8f564f98a1c196281610c46f: FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4249,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:16.239570   929 maintenance_manager.cc:419] P 78fc263d8f564f98a1c196281610c46f: Scheduling FlushMRSOp(6840cf69423546c88c3740cdb82e3978): perf score=1.000000
I20260812 06:17:16.273736   863 maintenance_manager.cc:643] P 78fc263d8f564f98a1c196281610c46f: FlushMRSOp(6840cf69423546c88c3740cdb82e3978) complete. Timing: real 0.034s	user 0.029s	sys 0.004s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":67,"dirs.run_cpu_time_us":192,"dirs.run_wall_time_us":1495,"drs_written":1,"lbm_read_time_us":59,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2056,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:17:16.274561   929 maintenance_manager.cc:419] P 78fc263d8f564f98a1c196281610c46f: Scheduling LogGCOp(6840cf69423546c88c3740cdb82e3978): free 120553636 bytes of WAL
I20260812 06:17:16.274840   863 log_reader.cc:385] T 6840cf69423546c88c3740cdb82e3978: removed 12 log segments from log reader
I20260812 06:17:16.274911   863 log.cc:1079] T 6840cf69423546c88c3740cdb82e3978 P 78fc263d8f564f98a1c196281610c46f: Deleting log segment in path: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431121259-757-0/minicluster-data/ts-0-root/wals/6840cf69423546c88c3740cdb82e3978/wal-000000028 (ops 137-141)
I20260812 06:17:16.274952   863 log.cc:1079] T 6840cf69423546c88c3740cdb82e3978 P 78fc263d8f564f98a1c196281610c46f: Deleting log segment in path: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431121259-757-0/minicluster-data/ts-0-root/wals/6840cf69423546c88c3740cdb82e3978/wal-000000029 (ops 142-146)
I20260812 06:17:16.274983   863 log.cc:1079] T 6840cf69423546c88c3740cdb82e3978 P 78fc263d8f564f98a1c196281610c46f: Deleting log segment in path: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431121259-757-0/minicluster-data/ts-0-root/wals/6840cf69423546c88c3740cdb82e3978/wal-000000030 (ops 147-151)
I20260812 06:17:16.275005   863 log.cc:1079] T 6840cf69423546c88c3740cdb82e3978 P 78fc263d8f564f98a1c196281610c46f: Deleting log segment in path: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431121259-757-0/minicluster-data/ts-0-root/wals/6840cf69423546c88c3740cdb82e3978/wal-000000031 (ops 152-156)
I20260812 06:17:16.275033   863 log.cc:1079] T 6840cf69423546c88c3740cdb82e3978 P 78fc263d8f564f98a1c196281610c46f: Deleting log segment in path: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431121259-757-0/minicluster-data/ts-0-root/wals/6840cf69423546c88c3740cdb82e3978/wal-000000032 (ops 157-161)
I20260812 06:17:16.275067   863 log.cc:1079] T 6840cf69423546c88c3740cdb82e3978 P 78fc263d8f564f98a1c196281610c46f: Deleting log segment in path: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431121259-757-0/minicluster-data/ts-0-root/wals/6840cf69423546c88c3740cdb82e3978/wal-000000033 (ops 162-166)
I20260812 06:17:16.275101   863 log.cc:1079] T 6840cf69423546c88c3740cdb82e3978 P 78fc263d8f564f98a1c196281610c46f: Deleting log segment in path: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431121259-757-0/minicluster-data/ts-0-root/wals/6840cf69423546c88c3740cdb82e3978/wal-000000034 (ops 167-171)
I20260812 06:17:16.275131   863 log.cc:1079] T 6840cf69423546c88c3740cdb82e3978 P 78fc263d8f564f98a1c196281610c46f: Deleting log segment in path: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431121259-757-0/minicluster-data/ts-0-root/wals/6840cf69423546c88c3740cdb82e3978/wal-000000035 (ops 172-176)
I20260812 06:17:16.275161   863 log.cc:1079] T 6840cf69423546c88c3740cdb82e3978 P 78fc263d8f564f98a1c196281610c46f: Deleting log segment in path: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431121259-757-0/minicluster-data/ts-0-root/wals/6840cf69423546c88c3740cdb82e3978/wal-000000036 (ops 177-180)
I20260812 06:17:16.275192   863 log.cc:1079] T 6840cf69423546c88c3740cdb82e3978 P 78fc263d8f564f98a1c196281610c46f: Deleting log segment in path: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431121259-757-0/minicluster-data/ts-0-root/wals/6840cf69423546c88c3740cdb82e3978/wal-000000037 (ops 181-185)
I20260812 06:17:16.275219   863 log.cc:1079] T 6840cf69423546c88c3740cdb82e3978 P 78fc263d8f564f98a1c196281610c46f: Deleting log segment in path: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431121259-757-0/minicluster-data/ts-0-root/wals/6840cf69423546c88c3740cdb82e3978/wal-000000038 (ops 186-190)
I20260812 06:17:16.275251   863 log.cc:1079] T 6840cf69423546c88c3740cdb82e3978 P 78fc263d8f564f98a1c196281610c46f: Deleting log segment in path: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515431121259-757-0/minicluster-data/ts-0-root/wals/6840cf69423546c88c3740cdb82e3978/wal-000000039 (ops 191-194)
I20260812 06:17:16.303804   863 maintenance_manager.cc:643] P 78fc263d8f564f98a1c196281610c46f: LogGCOp(6840cf69423546c88c3740cdb82e3978) complete. Timing: real 0.029s	user 0.000s	sys 0.028s Metrics: {}
I20260812 06:17:16.304355   929 maintenance_manager.cc:419] P 78fc263d8f564f98a1c196281610c46f: Scheduling UndoDeltaBlockGCOp(6840cf69423546c88c3740cdb82e3978): 483 bytes on disk
I20260812 06:17:16.305109   863 maintenance_manager.cc:643] P 78fc263d8f564f98a1c196281610c46f: UndoDeltaBlockGCOp(6840cf69423546c88c3740cdb82e3978) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":110,"lbm_reads_lt_1ms":4}
I20260812 06:17:16.305843   929 maintenance_manager.cc:419] P 78fc263d8f564f98a1c196281610c46f: Scheduling FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978): perf score=2.188937
I20260812 06:17:16.329865   863 maintenance_manager.cc:643] P 78fc263d8f564f98a1c196281610c46f: FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978) complete. Timing: real 0.024s	user 0.006s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4281,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:16.330442   929 maintenance_manager.cc:419] P 78fc263d8f564f98a1c196281610c46f: Scheduling FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978): perf score=2.188937
I20260812 06:17:16.341471   863 maintenance_manager.cc:643] P 78fc263d8f564f98a1c196281610c46f: FlushDeltaMemStoresOp(6840cf69423546c88c3740cdb82e3978) complete. Timing: real 0.011s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4413,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:16.341926   929 maintenance_manager.cc:419] P 78fc263d8f564f98a1c196281610c46f: Scheduling MajorDeltaCompactionOp(6840cf69423546c88c3740cdb82e3978): perf score=1.000000
I20260812 06:17:16.392359   757 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.965s	user 1.873s	sys 0.102s
I20260812 06:17:16.481781   757 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.089s	user 0.001s	sys 0.000s
I20260812 06:17:16.482546   757 tablet_server.cc:179] TabletServer@127.0.189.65:0 shutting down...
I20260812 06:17:16.525763   863 maintenance_manager.cc:643] P 78fc263d8f564f98a1c196281610c46f: MajorDeltaCompactionOp(6840cf69423546c88c3740cdb82e3978) complete. Timing: real 0.184s	user 0.131s	sys 0.052s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877338,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1797,"lbm_read_time_us":14821,"lbm_reads_lt_1ms":670,"lbm_write_time_us":29458,"lbm_writes_lt_1ms":643,"mutex_wait_us":91,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":12160,"thread_start_us":109,"threads_started":1,"update_count":3000}
I20260812 06:17:16.527201   757 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:16.527668   757 tablet_replica.cc:333] T 6840cf69423546c88c3740cdb82e3978 P 78fc263d8f564f98a1c196281610c46f: stopping tablet replica
I20260812 06:17:16.527957   757 raft_consensus.cc:2243] T 6840cf69423546c88c3740cdb82e3978 P 78fc263d8f564f98a1c196281610c46f [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:16.528240   757 raft_consensus.cc:2272] T 6840cf69423546c88c3740cdb82e3978 P 78fc263d8f564f98a1c196281610c46f [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:16.546177   757 tablet_server.cc:196] TabletServer@127.0.189.65:0 shutdown complete.
I20260812 06:17:16.577167   757 master.cc:562] Master@127.0.189.126:33087 shutting down...
I20260812 06:17:16.581283   757 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 98063d1e69ee4a7081bc0c5135c9281d [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:16.581558   757 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 98063d1e69ee4a7081bc0c5135c9281d [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:16.581665   757 tablet_replica.cc:333] T 00000000000000000000000000000000 P 98063d1e69ee4a7081bc0c5135c9281d: stopping tablet replica
I20260812 06:17:16.594280   757 master.cc:584] Master@127.0.189.126:33087 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5547 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:17:16.694252   757 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.0.189.126:38545
I20260812 06:17:16.694777   757 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:16.697378   961 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:17:16.697458   757 server_base.cc:1061] running on GCE node
W20260812 06:17:16.697520   963 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:16.697378   960 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:16.697816   757 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:16.697886   757 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:16.697914   757 hybrid_clock.cc:648] HybridClock initialized: now 1786515436697913 us; error 0 us; skew 500 ppm
I20260812 06:17:16.699023   757 webserver.cc:533] Webserver started at http://127.0.189.126:41513/ using document root <none> and password file <none>
I20260812 06:17:16.699230   757 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:16.699309   757 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:16.699425   757 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:16.699882   757 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431121259-757-0/minicluster-data/master-0-root/instance:
uuid: "9c0ced44706d42c4b08f9d0f509ceffb"
format_stamp: "Formatted at 2026-08-12 06:17:16 on dist-test-slave-zpfg"
I20260812 06:17:16.701707   757 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:16.703644   969 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:16.704038   757 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.000s
I20260812 06:17:16.704133   757 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431121259-757-0/minicluster-data/master-0-root
uuid: "9c0ced44706d42c4b08f9d0f509ceffb"
format_stamp: "Formatted at 2026-08-12 06:17:16 on dist-test-slave-zpfg"
I20260812 06:17:16.704226   757 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431121259-757-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431121259-757-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431121259-757-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:16.726133   757 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:16.726651   757 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:16.731419   757 rpc_server.cc:307] RPC server started. Bound to: 127.0.189.126:38545
I20260812 06:17:16.737640  1026 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.0.189.126:38545 every 8 connection(s)
I20260812 06:17:16.738106  1027 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:16.740023  1027 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 9c0ced44706d42c4b08f9d0f509ceffb: Bootstrap starting.
I20260812 06:17:16.740890  1027 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 9c0ced44706d42c4b08f9d0f509ceffb: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:16.742035  1027 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 9c0ced44706d42c4b08f9d0f509ceffb: No bootstrap required, opened a new log
I20260812 06:17:16.742556  1027 raft_consensus.cc:359] T 00000000000000000000000000000000 P 9c0ced44706d42c4b08f9d0f509ceffb [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9c0ced44706d42c4b08f9d0f509ceffb" member_type: VOTER }
I20260812 06:17:16.742674  1027 raft_consensus.cc:385] T 00000000000000000000000000000000 P 9c0ced44706d42c4b08f9d0f509ceffb [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:16.742723  1027 raft_consensus.cc:740] T 00000000000000000000000000000000 P 9c0ced44706d42c4b08f9d0f509ceffb [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 9c0ced44706d42c4b08f9d0f509ceffb, State: Initialized, Role: FOLLOWER
I20260812 06:17:16.742885  1027 consensus_queue.cc:260] T 00000000000000000000000000000000 P 9c0ced44706d42c4b08f9d0f509ceffb [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: "9c0ced44706d42c4b08f9d0f509ceffb" member_type: VOTER }
I20260812 06:17:16.742980  1027 raft_consensus.cc:399] T 00000000000000000000000000000000 P 9c0ced44706d42c4b08f9d0f509ceffb [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:16.743027  1027 raft_consensus.cc:493] T 00000000000000000000000000000000 P 9c0ced44706d42c4b08f9d0f509ceffb [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:16.743083  1027 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 9c0ced44706d42c4b08f9d0f509ceffb [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:16.743811  1027 raft_consensus.cc:515] T 00000000000000000000000000000000 P 9c0ced44706d42c4b08f9d0f509ceffb [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9c0ced44706d42c4b08f9d0f509ceffb" member_type: VOTER }
I20260812 06:17:16.743968  1027 leader_election.cc:304] T 00000000000000000000000000000000 P 9c0ced44706d42c4b08f9d0f509ceffb [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: 9c0ced44706d42c4b08f9d0f509ceffb; no voters: 
I20260812 06:17:16.744187  1027 leader_election.cc:290] T 00000000000000000000000000000000 P 9c0ced44706d42c4b08f9d0f509ceffb [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:16.744417  1030 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 9c0ced44706d42c4b08f9d0f509ceffb [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:16.744653  1030 raft_consensus.cc:697] T 00000000000000000000000000000000 P 9c0ced44706d42c4b08f9d0f509ceffb [term 1 LEADER]: Becoming Leader. State: Replica: 9c0ced44706d42c4b08f9d0f509ceffb, State: Running, Role: LEADER
I20260812 06:17:16.744689  1027 sys_catalog.cc:565] T 00000000000000000000000000000000 P 9c0ced44706d42c4b08f9d0f509ceffb [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:16.744822  1030 consensus_queue.cc:237] T 00000000000000000000000000000000 P 9c0ced44706d42c4b08f9d0f509ceffb [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: "9c0ced44706d42c4b08f9d0f509ceffb" member_type: VOTER }
I20260812 06:17:16.745338  1031 sys_catalog.cc:455] T 00000000000000000000000000000000 P 9c0ced44706d42c4b08f9d0f509ceffb [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "9c0ced44706d42c4b08f9d0f509ceffb" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9c0ced44706d42c4b08f9d0f509ceffb" member_type: VOTER } }
I20260812 06:17:16.745443  1031 sys_catalog.cc:458] T 00000000000000000000000000000000 P 9c0ced44706d42c4b08f9d0f509ceffb [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:16.745421  1032 sys_catalog.cc:455] T 00000000000000000000000000000000 P 9c0ced44706d42c4b08f9d0f509ceffb [sys.catalog]: SysCatalogTable state changed. Reason: New leader 9c0ced44706d42c4b08f9d0f509ceffb. Latest consensus state: current_term: 1 leader_uuid: "9c0ced44706d42c4b08f9d0f509ceffb" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "9c0ced44706d42c4b08f9d0f509ceffb" member_type: VOTER } }
I20260812 06:17:16.745486  1032 sys_catalog.cc:458] T 00000000000000000000000000000000 P 9c0ced44706d42c4b08f9d0f509ceffb [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:16.745765  1038 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:16.746796  1038 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:16.746994   757 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:16.748744  1038 catalog_manager.cc:1383] Generated new cluster ID: edb41cac771b4195a6f800763272178b
I20260812 06:17:16.748821  1038 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:16.755491  1038 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:16.756197  1038 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:16.765223  1038 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 9c0ced44706d42c4b08f9d0f509ceffb: Generated new TSK 0
I20260812 06:17:16.765480  1038 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:16.779955   757 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:16.782840  1053 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:16.782969  1050 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:16.782835  1049 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:16.783522   757 server_base.cc:1061] running on GCE node
I20260812 06:17:16.783720   757 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:16.783795   757 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:16.783833   757 hybrid_clock.cc:648] HybridClock initialized: now 1786515436783832 us; error 0 us; skew 500 ppm
I20260812 06:17:16.784881   757 webserver.cc:533] Webserver started at http://127.0.189.65:40299/ using document root <none> and password file <none>
I20260812 06:17:16.785081   757 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:16.785159   757 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:16.785249   757 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:16.785738   757 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431121259-757-0/minicluster-data/ts-0-root/instance:
uuid: "2dc7e75f19e747669c8cb628ba0a23c2"
format_stamp: "Formatted at 2026-08-12 06:17:16 on dist-test-slave-zpfg"
I20260812 06:17:16.787701   757 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:17:16.788919  1058 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:16.789206   757 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:17:16.789357   757 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431121259-757-0/minicluster-data/ts-0-root
uuid: "2dc7e75f19e747669c8cb628ba0a23c2"
format_stamp: "Formatted at 2026-08-12 06:17:16 on dist-test-slave-zpfg"
I20260812 06:17:16.789444   757 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431121259-757-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431121259-757-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431121259-757-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:16.811352   757 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:16.811868   757 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:16.812239   757 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:16.812793   757 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:16.812836   757 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:16.812903   757 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:16.812947   757 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:16.818188   757 rpc_server.cc:307] RPC server started. Bound to: 127.0.189.65:36187
I20260812 06:17:16.818420  1126 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.0.189.65:36187 every 8 connection(s)
I20260812 06:17:16.828231  1128 heartbeater.cc:344] Connected to a master server at 127.0.189.126:38545
I20260812 06:17:16.828408  1128 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:16.828712  1128 heartbeater.cc:507] Master 127.0.189.126:38545 requested a full tablet report, sending...
I20260812 06:17:16.829528   989 ts_manager.cc:194] Registered new tserver with Master: 2dc7e75f19e747669c8cb628ba0a23c2 (127.0.189.65:36187)
I20260812 06:17:16.829974   757 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.011193808s
I20260812 06:17:16.830552   989 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:38990
I20260812 06:17:16.838464   989 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:39000:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:17:16.848956  1087 tablet_service.cc:1511] Processing CreateTablet for tablet ee564200b86c468fb85a878822eaa27d (DEFAULT_TABLE table=heavy-update-compaction-test [id=80e5a067048b45c8a5b451292c13bf7f]), partition=
I20260812 06:17:16.849249  1087 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet ee564200b86c468fb85a878822eaa27d. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:16.851853  1140 tablet_bootstrap.cc:492] T ee564200b86c468fb85a878822eaa27d P 2dc7e75f19e747669c8cb628ba0a23c2: Bootstrap starting.
I20260812 06:17:16.852844  1140 tablet_bootstrap.cc:654] T ee564200b86c468fb85a878822eaa27d P 2dc7e75f19e747669c8cb628ba0a23c2: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:16.854226  1140 tablet_bootstrap.cc:492] T ee564200b86c468fb85a878822eaa27d P 2dc7e75f19e747669c8cb628ba0a23c2: No bootstrap required, opened a new log
I20260812 06:17:16.854321  1140 ts_tablet_manager.cc:1403] T ee564200b86c468fb85a878822eaa27d P 2dc7e75f19e747669c8cb628ba0a23c2: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:17:16.854820  1140 raft_consensus.cc:359] T ee564200b86c468fb85a878822eaa27d P 2dc7e75f19e747669c8cb628ba0a23c2 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2dc7e75f19e747669c8cb628ba0a23c2" member_type: VOTER last_known_addr { host: "127.0.189.65" port: 36187 } }
I20260812 06:17:16.854916  1140 raft_consensus.cc:385] T ee564200b86c468fb85a878822eaa27d P 2dc7e75f19e747669c8cb628ba0a23c2 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:16.854938  1140 raft_consensus.cc:740] T ee564200b86c468fb85a878822eaa27d P 2dc7e75f19e747669c8cb628ba0a23c2 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 2dc7e75f19e747669c8cb628ba0a23c2, State: Initialized, Role: FOLLOWER
I20260812 06:17:16.855037  1140 consensus_queue.cc:260] T ee564200b86c468fb85a878822eaa27d P 2dc7e75f19e747669c8cb628ba0a23c2 [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: "2dc7e75f19e747669c8cb628ba0a23c2" member_type: VOTER last_known_addr { host: "127.0.189.65" port: 36187 } }
I20260812 06:17:16.855098  1140 raft_consensus.cc:399] T ee564200b86c468fb85a878822eaa27d P 2dc7e75f19e747669c8cb628ba0a23c2 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:16.855119  1140 raft_consensus.cc:493] T ee564200b86c468fb85a878822eaa27d P 2dc7e75f19e747669c8cb628ba0a23c2 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:16.855147  1140 raft_consensus.cc:3060] T ee564200b86c468fb85a878822eaa27d P 2dc7e75f19e747669c8cb628ba0a23c2 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:16.855867  1140 raft_consensus.cc:515] T ee564200b86c468fb85a878822eaa27d P 2dc7e75f19e747669c8cb628ba0a23c2 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2dc7e75f19e747669c8cb628ba0a23c2" member_type: VOTER last_known_addr { host: "127.0.189.65" port: 36187 } }
I20260812 06:17:16.855990  1140 leader_election.cc:304] T ee564200b86c468fb85a878822eaa27d P 2dc7e75f19e747669c8cb628ba0a23c2 [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: 2dc7e75f19e747669c8cb628ba0a23c2; no voters: 
I20260812 06:17:16.856184  1140 leader_election.cc:290] T ee564200b86c468fb85a878822eaa27d P 2dc7e75f19e747669c8cb628ba0a23c2 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:16.856348  1142 raft_consensus.cc:2804] T ee564200b86c468fb85a878822eaa27d P 2dc7e75f19e747669c8cb628ba0a23c2 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:16.856505  1140 ts_tablet_manager.cc:1434] T ee564200b86c468fb85a878822eaa27d P 2dc7e75f19e747669c8cb628ba0a23c2: Time spent starting tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:16.856532  1128 heartbeater.cc:499] Master 127.0.189.126:38545 was elected leader, sending a full tablet report...
I20260812 06:17:16.856608  1142 raft_consensus.cc:697] T ee564200b86c468fb85a878822eaa27d P 2dc7e75f19e747669c8cb628ba0a23c2 [term 1 LEADER]: Becoming Leader. State: Replica: 2dc7e75f19e747669c8cb628ba0a23c2, State: Running, Role: LEADER
I20260812 06:17:16.856853  1142 consensus_queue.cc:237] T ee564200b86c468fb85a878822eaa27d P 2dc7e75f19e747669c8cb628ba0a23c2 [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: "2dc7e75f19e747669c8cb628ba0a23c2" member_type: VOTER last_known_addr { host: "127.0.189.65" port: 36187 } }
I20260812 06:17:16.858546   989 catalog_manager.cc:5719] T ee564200b86c468fb85a878822eaa27d P 2dc7e75f19e747669c8cb628ba0a23c2 reported cstate change: term changed from 0 to 1, leader changed from <none> to 2dc7e75f19e747669c8cb628ba0a23c2 (127.0.189.65). New cstate: current_term: 1 leader_uuid: "2dc7e75f19e747669c8cb628ba0a23c2" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "2dc7e75f19e747669c8cb628ba0a23c2" member_type: VOTER last_known_addr { host: "127.0.189.65" port: 36187 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:16.921020   757 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.057s	user 0.019s	sys 0.004s
I20260812 06:17:17.069309  1129 maintenance_manager.cc:419] P 2dc7e75f19e747669c8cb628ba0a23c2: Scheduling FlushMRSOp(ee564200b86c468fb85a878822eaa27d): perf score=19.054940
I20260812 06:17:17.236866  1064 maintenance_manager.cc:643] P 2dc7e75f19e747669c8cb628ba0a23c2: FlushMRSOp(ee564200b86c468fb85a878822eaa27d) complete. Timing: real 0.167s	user 0.125s	sys 0.039s Metrics: {"bytes_written":12307490,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":67,"dirs.run_cpu_time_us":214,"dirs.run_wall_time_us":907,"drs_written":1,"lbm_read_time_us":44,"lbm_reads_lt_1ms":4,"lbm_write_time_us":43424,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1500}
I20260812 06:17:17.237591  1129 maintenance_manager.cc:419] P 2dc7e75f19e747669c8cb628ba0a23c2: Scheduling LogGCOp(ee564200b86c468fb85a878822eaa27d): free 20743880 bytes of WAL
I20260812 06:17:17.237859  1064 log_reader.cc:385] T ee564200b86c468fb85a878822eaa27d: removed 2 log segments from log reader
I20260812 06:17:17.237905  1064 log.cc:1079] T ee564200b86c468fb85a878822eaa27d P 2dc7e75f19e747669c8cb628ba0a23c2: Deleting log segment in path: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431121259-757-0/minicluster-data/ts-0-root/wals/ee564200b86c468fb85a878822eaa27d/wal-000000001 (ops 1-6)
I20260812 06:17:17.237936  1064 log.cc:1079] T ee564200b86c468fb85a878822eaa27d P 2dc7e75f19e747669c8cb628ba0a23c2: Deleting log segment in path: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431121259-757-0/minicluster-data/ts-0-root/wals/ee564200b86c468fb85a878822eaa27d/wal-000000002 (ops 7-11)
I20260812 06:17:17.242416  1064 maintenance_manager.cc:643] P 2dc7e75f19e747669c8cb628ba0a23c2: LogGCOp(ee564200b86c468fb85a878822eaa27d) complete. Timing: real 0.005s	user 0.001s	sys 0.003s Metrics: {}
I20260812 06:17:17.242870  1129 maintenance_manager.cc:419] P 2dc7e75f19e747669c8cb628ba0a23c2: Scheduling FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d): perf score=2.188937
I20260812 06:17:17.255854  1064 maintenance_manager.cc:643] P 2dc7e75f19e747669c8cb628ba0a23c2: FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d) complete. Timing: real 0.013s	user 0.005s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4539,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:17.256444  1129 maintenance_manager.cc:419] P 2dc7e75f19e747669c8cb628ba0a23c2: Scheduling UndoDeltaBlockGCOp(ee564200b86c468fb85a878822eaa27d): 16411393 bytes on disk
I20260812 06:17:17.256942  1064 maintenance_manager.cc:643] P 2dc7e75f19e747669c8cb628ba0a23c2: UndoDeltaBlockGCOp(ee564200b86c468fb85a878822eaa27d) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":57,"lbm_reads_lt_1ms":4}
I20260812 06:17:17.257462  1129 maintenance_manager.cc:419] P 2dc7e75f19e747669c8cb628ba0a23c2: Scheduling MajorDeltaCompactionOp(ee564200b86c468fb85a878822eaa27d): perf score=1.000000
I20260812 06:17:17.424849  1064 maintenance_manager.cc:643] P 2dc7e75f19e747669c8cb628ba0a23c2: MajorDeltaCompactionOp(ee564200b86c468fb85a878822eaa27d) complete. Timing: real 0.167s	user 0.120s	sys 0.047s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1069,"lbm_read_time_us":12265,"lbm_reads_lt_1ms":464,"lbm_write_time_us":26493,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7424,"thread_start_us":378,"threads_started":5,"update_count":2000}
I20260812 06:17:17.425635  1129 maintenance_manager.cc:419] P 2dc7e75f19e747669c8cb628ba0a23c2: Scheduling FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d): perf score=10.126437
I20260812 06:17:17.464236  1064 maintenance_manager.cc:643] P 2dc7e75f19e747669c8cb628ba0a23c2: FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d) complete. Timing: real 0.038s	user 0.020s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16840,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:17:17.464839  1129 maintenance_manager.cc:419] P 2dc7e75f19e747669c8cb628ba0a23c2: Scheduling FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d): perf score=2.188937
I20260812 06:17:17.489039  1064 maintenance_manager.cc:643] P 2dc7e75f19e747669c8cb628ba0a23c2: FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d) complete. Timing: real 0.024s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5599,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:17.489560  1129 maintenance_manager.cc:419] P 2dc7e75f19e747669c8cb628ba0a23c2: Scheduling FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d): perf score=2.188937
I20260812 06:17:17.501081  1064 maintenance_manager.cc:643] P 2dc7e75f19e747669c8cb628ba0a23c2: FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4086,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:17.501736  1129 maintenance_manager.cc:419] P 2dc7e75f19e747669c8cb628ba0a23c2: Scheduling MajorDeltaCompactionOp(ee564200b86c468fb85a878822eaa27d): perf score=1.000000
I20260812 06:17:17.687876  1064 maintenance_manager.cc:643] P 2dc7e75f19e747669c8cb628ba0a23c2: MajorDeltaCompactionOp(ee564200b86c468fb85a878822eaa27d) complete. Timing: real 0.186s	user 0.123s	sys 0.059s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774807,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":237,"lbm_read_time_us":9662,"lbm_reads_lt_1ms":573,"lbm_write_time_us":31850,"lbm_writes_lt_1ms":543,"mutex_wait_us":2,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2500}
I20260812 06:17:17.688473  1129 maintenance_manager.cc:419] P 2dc7e75f19e747669c8cb628ba0a23c2: Scheduling FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d): perf score=14.095187
I20260812 06:17:17.750563  1064 maintenance_manager.cc:643] P 2dc7e75f19e747669c8cb628ba0a23c2: FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d) complete. Timing: real 0.062s	user 0.035s	sys 0.027s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":26942,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:17.751042  1129 maintenance_manager.cc:419] P 2dc7e75f19e747669c8cb628ba0a23c2: Scheduling FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d): perf score=2.188937
I20260812 06:17:17.764578  1064 maintenance_manager.cc:643] P 2dc7e75f19e747669c8cb628ba0a23c2: FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d) complete. Timing: real 0.013s	user 0.004s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5111,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:17.765079  1129 maintenance_manager.cc:419] P 2dc7e75f19e747669c8cb628ba0a23c2: Scheduling MajorDeltaCompactionOp(ee564200b86c468fb85a878822eaa27d): perf score=1.000000
I20260812 06:17:17.938566  1064 maintenance_manager.cc:643] P 2dc7e75f19e747669c8cb628ba0a23c2: MajorDeltaCompactionOp(ee564200b86c468fb85a878822eaa27d) complete. Timing: real 0.173s	user 0.123s	sys 0.050s 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":341,"lbm_read_time_us":12471,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32024,"lbm_writes_lt_1ms":543,"mutex_wait_us":21,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13440,"update_count":2500}
I20260812 06:17:17.939430  1129 maintenance_manager.cc:419] P 2dc7e75f19e747669c8cb628ba0a23c2: Scheduling FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d): perf score=10.126437
I20260812 06:17:17.975559  1064 maintenance_manager.cc:643] P 2dc7e75f19e747669c8cb628ba0a23c2: FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d) complete. Timing: real 0.036s	user 0.030s	sys 0.005s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":14901,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:17.976277  1129 maintenance_manager.cc:419] P 2dc7e75f19e747669c8cb628ba0a23c2: Scheduling FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d): perf score=2.188937
I20260812 06:17:17.997605  1064 maintenance_manager.cc:643] P 2dc7e75f19e747669c8cb628ba0a23c2: FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d) complete. Timing: real 0.021s	user 0.009s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7325,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:17.998214  1129 maintenance_manager.cc:419] P 2dc7e75f19e747669c8cb628ba0a23c2: Scheduling MajorDeltaCompactionOp(ee564200b86c468fb85a878822eaa27d): perf score=1.000000
I20260812 06:17:18.128345  1064 maintenance_manager.cc:643] P 2dc7e75f19e747669c8cb628ba0a23c2: MajorDeltaCompactionOp(ee564200b86c468fb85a878822eaa27d) complete. Timing: real 0.130s	user 0.096s	sys 0.033s 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":540,"lbm_read_time_us":9215,"lbm_reads_lt_1ms":464,"lbm_write_time_us":25302,"lbm_writes_lt_1ms":443,"mutex_wait_us":39,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":15488,"update_count":2000}
I20260812 06:17:18.128835  1129 maintenance_manager.cc:419] P 2dc7e75f19e747669c8cb628ba0a23c2: Scheduling FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d): perf score=10.126437
I20260812 06:17:18.175349  1064 maintenance_manager.cc:643] P 2dc7e75f19e747669c8cb628ba0a23c2: FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d) complete. Timing: real 0.046s	user 0.025s	sys 0.015s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":17864,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:18.175810  1129 maintenance_manager.cc:419] P 2dc7e75f19e747669c8cb628ba0a23c2: Scheduling FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d): perf score=2.188937
I20260812 06:17:18.186323  1064 maintenance_manager.cc:643] P 2dc7e75f19e747669c8cb628ba0a23c2: FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3963,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:18.187125  1129 maintenance_manager.cc:419] P 2dc7e75f19e747669c8cb628ba0a23c2: Scheduling MajorDeltaCompactionOp(ee564200b86c468fb85a878822eaa27d): perf score=1.000000
I20260812 06:17:18.317041  1064 maintenance_manager.cc:643] P 2dc7e75f19e747669c8cb628ba0a23c2: MajorDeltaCompactionOp(ee564200b86c468fb85a878822eaa27d) complete. Timing: real 0.130s	user 0.101s	sys 0.028s 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":313,"lbm_read_time_us":7804,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25411,"lbm_writes_lt_1ms":443,"mutex_wait_us":60,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6912,"update_count":2000}
I20260812 06:17:18.317674  1129 maintenance_manager.cc:419] P 2dc7e75f19e747669c8cb628ba0a23c2: Scheduling FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d): perf score=11.118625
I20260812 06:17:18.365331  1064 maintenance_manager.cc:643] P 2dc7e75f19e747669c8cb628ba0a23c2: FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d) complete. Timing: real 0.047s	user 0.022s	sys 0.023s Metrics: {"bytes_written":12594659,"delete_count":0,"lbm_write_time_us":15695,"lbm_writes_lt_1ms":310,"reinsert_count":0,"update_count":1535}
I20260812 06:17:18.366057  1129 maintenance_manager.cc:419] P 2dc7e75f19e747669c8cb628ba0a23c2: Scheduling FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d): perf score=2.188937
I20260812 06:17:18.385017  1064 maintenance_manager.cc:643] P 2dc7e75f19e747669c8cb628ba0a23c2: FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d) complete. Timing: real 0.019s	user 0.009s	sys 0.007s Metrics: {"bytes_written":3815484,"delete_count":0,"lbm_write_time_us":7161,"lbm_writes_lt_1ms":96,"reinsert_count":0,"update_count":465}
I20260812 06:17:18.385648  1129 maintenance_manager.cc:419] P 2dc7e75f19e747669c8cb628ba0a23c2: Scheduling MajorDeltaCompactionOp(ee564200b86c468fb85a878822eaa27d): perf score=1.000000
I20260812 06:17:18.534381  1064 maintenance_manager.cc:643] P 2dc7e75f19e747669c8cb628ba0a23c2: MajorDeltaCompactionOp(ee564200b86c468fb85a878822eaa27d) complete. Timing: real 0.149s	user 0.098s	sys 0.051s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672271,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":343,"lbm_read_time_us":11182,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21540,"lbm_writes_lt_1ms":443,"mutex_wait_us":2,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12928,"update_count":2000}
I20260812 06:17:18.535123  1129 maintenance_manager.cc:419] P 2dc7e75f19e747669c8cb628ba0a23c2: Scheduling FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d): perf score=10.126437
I20260812 06:17:18.574111  1064 maintenance_manager.cc:643] P 2dc7e75f19e747669c8cb628ba0a23c2: FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d) complete. Timing: real 0.039s	user 0.024s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16903,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:18.574729  1129 maintenance_manager.cc:419] P 2dc7e75f19e747669c8cb628ba0a23c2: Scheduling FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d): perf score=2.188937
I20260812 06:17:18.587641  1064 maintenance_manager.cc:643] P 2dc7e75f19e747669c8cb628ba0a23c2: FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d) complete. Timing: real 0.013s	user 0.009s	sys 0.002s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4830,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:18.588291  1129 maintenance_manager.cc:419] P 2dc7e75f19e747669c8cb628ba0a23c2: Scheduling FlushMRSOp(ee564200b86c468fb85a878822eaa27d): perf score=1.000000
I20260812 06:17:18.616636  1064 maintenance_manager.cc:643] P 2dc7e75f19e747669c8cb628ba0a23c2: FlushMRSOp(ee564200b86c468fb85a878822eaa27d) complete. Timing: real 0.028s	user 0.026s	sys 0.001s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":87,"dirs.run_cpu_time_us":220,"dirs.run_wall_time_us":1402,"drs_written":1,"lbm_read_time_us":47,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1585,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:17:18.617290  1129 maintenance_manager.cc:419] P 2dc7e75f19e747669c8cb628ba0a23c2: Scheduling LogGCOp(ee564200b86c468fb85a878822eaa27d): free 121006437 bytes of WAL
I20260812 06:17:18.617640  1064 log_reader.cc:385] T ee564200b86c468fb85a878822eaa27d: removed 12 log segments from log reader
I20260812 06:17:18.617702  1064 log.cc:1079] T ee564200b86c468fb85a878822eaa27d P 2dc7e75f19e747669c8cb628ba0a23c2: Deleting log segment in path: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431121259-757-0/minicluster-data/ts-0-root/wals/ee564200b86c468fb85a878822eaa27d/wal-000000003 (ops 12-16)
I20260812 06:17:18.617826  1064 log.cc:1079] T ee564200b86c468fb85a878822eaa27d P 2dc7e75f19e747669c8cb628ba0a23c2: Deleting log segment in path: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431121259-757-0/minicluster-data/ts-0-root/wals/ee564200b86c468fb85a878822eaa27d/wal-000000004 (ops 17-21)
I20260812 06:17:18.617897  1064 log.cc:1079] T ee564200b86c468fb85a878822eaa27d P 2dc7e75f19e747669c8cb628ba0a23c2: Deleting log segment in path: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431121259-757-0/minicluster-data/ts-0-root/wals/ee564200b86c468fb85a878822eaa27d/wal-000000005 (ops 22-26)
I20260812 06:17:18.617980  1064 log.cc:1079] T ee564200b86c468fb85a878822eaa27d P 2dc7e75f19e747669c8cb628ba0a23c2: Deleting log segment in path: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431121259-757-0/minicluster-data/ts-0-root/wals/ee564200b86c468fb85a878822eaa27d/wal-000000006 (ops 27-31)
I20260812 06:17:18.618040  1064 log.cc:1079] T ee564200b86c468fb85a878822eaa27d P 2dc7e75f19e747669c8cb628ba0a23c2: Deleting log segment in path: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431121259-757-0/minicluster-data/ts-0-root/wals/ee564200b86c468fb85a878822eaa27d/wal-000000007 (ops 32-36)
I20260812 06:17:18.618135  1064 log.cc:1079] T ee564200b86c468fb85a878822eaa27d P 2dc7e75f19e747669c8cb628ba0a23c2: Deleting log segment in path: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431121259-757-0/minicluster-data/ts-0-root/wals/ee564200b86c468fb85a878822eaa27d/wal-000000008 (ops 37-41)
I20260812 06:17:18.618204  1064 log.cc:1079] T ee564200b86c468fb85a878822eaa27d P 2dc7e75f19e747669c8cb628ba0a23c2: Deleting log segment in path: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431121259-757-0/minicluster-data/ts-0-root/wals/ee564200b86c468fb85a878822eaa27d/wal-000000009 (ops 42-46)
I20260812 06:17:18.618251  1064 log.cc:1079] T ee564200b86c468fb85a878822eaa27d P 2dc7e75f19e747669c8cb628ba0a23c2: Deleting log segment in path: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431121259-757-0/minicluster-data/ts-0-root/wals/ee564200b86c468fb85a878822eaa27d/wal-000000010 (ops 47-50)
I20260812 06:17:18.618294  1064 log.cc:1079] T ee564200b86c468fb85a878822eaa27d P 2dc7e75f19e747669c8cb628ba0a23c2: Deleting log segment in path: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431121259-757-0/minicluster-data/ts-0-root/wals/ee564200b86c468fb85a878822eaa27d/wal-000000011 (ops 51-55)
I20260812 06:17:18.618376  1064 log.cc:1079] T ee564200b86c468fb85a878822eaa27d P 2dc7e75f19e747669c8cb628ba0a23c2: Deleting log segment in path: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431121259-757-0/minicluster-data/ts-0-root/wals/ee564200b86c468fb85a878822eaa27d/wal-000000012 (ops 56-60)
I20260812 06:17:18.618427  1064 log.cc:1079] T ee564200b86c468fb85a878822eaa27d P 2dc7e75f19e747669c8cb628ba0a23c2: Deleting log segment in path: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431121259-757-0/minicluster-data/ts-0-root/wals/ee564200b86c468fb85a878822eaa27d/wal-000000013 (ops 61-65)
I20260812 06:17:18.618464  1064 log.cc:1079] T ee564200b86c468fb85a878822eaa27d P 2dc7e75f19e747669c8cb628ba0a23c2: Deleting log segment in path: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431121259-757-0/minicluster-data/ts-0-root/wals/ee564200b86c468fb85a878822eaa27d/wal-000000014 (ops 66-70)
I20260812 06:17:18.645254  1064 maintenance_manager.cc:643] P 2dc7e75f19e747669c8cb628ba0a23c2: LogGCOp(ee564200b86c468fb85a878822eaa27d) complete. Timing: real 0.028s	user 0.002s	sys 0.023s Metrics: {}
I20260812 06:17:18.645910  1129 maintenance_manager.cc:419] P 2dc7e75f19e747669c8cb628ba0a23c2: Scheduling FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d): perf score=6.157687
I20260812 06:17:18.679179  1064 maintenance_manager.cc:643] P 2dc7e75f19e747669c8cb628ba0a23c2: FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d) complete. Timing: real 0.033s	user 0.015s	sys 0.012s Metrics: {"bytes_written":8205077,"delete_count":0,"lbm_write_time_us":9333,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:17:18.679709  1129 maintenance_manager.cc:419] P 2dc7e75f19e747669c8cb628ba0a23c2: Scheduling UndoDeltaBlockGCOp(ee564200b86c468fb85a878822eaa27d): 472 bytes on disk
I20260812 06:17:18.680222  1064 maintenance_manager.cc:643] P 2dc7e75f19e747669c8cb628ba0a23c2: UndoDeltaBlockGCOp(ee564200b86c468fb85a878822eaa27d) 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:17:18.680742  1129 maintenance_manager.cc:419] P 2dc7e75f19e747669c8cb628ba0a23c2: Scheduling FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d): perf score=1.000000
I20260812 06:17:18.688597  1064 maintenance_manager.cc:643] P 2dc7e75f19e747669c8cb628ba0a23c2: FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d) complete. Timing: real 0.008s	user 0.003s	sys 0.000s Metrics: {"bytes_written":1148856,"delete_count":0,"lbm_write_time_us":1101,"lbm_writes_lt_1ms":31,"reinsert_count":0,"update_count":140}
I20260812 06:17:18.689033  1129 maintenance_manager.cc:419] P 2dc7e75f19e747669c8cb628ba0a23c2: Scheduling FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d): perf score=1.196750
I20260812 06:17:18.697474  1064 maintenance_manager.cc:643] P 2dc7e75f19e747669c8cb628ba0a23c2: FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d) complete. Timing: real 0.008s	user 0.007s	sys 0.000s Metrics: {"bytes_written":2953955,"delete_count":0,"lbm_write_time_us":3042,"lbm_writes_lt_1ms":75,"reinsert_count":0,"update_count":360}
I20260812 06:17:18.697953  1129 maintenance_manager.cc:419] P 2dc7e75f19e747669c8cb628ba0a23c2: Scheduling MajorDeltaCompactionOp(ee564200b86c468fb85a878822eaa27d): perf score=1.000000
I20260812 06:17:18.936854  1064 maintenance_manager.cc:643] P 2dc7e75f19e747669c8cb628ba0a23c2: MajorDeltaCompactionOp(ee564200b86c468fb85a878822eaa27d) complete. Timing: real 0.239s	user 0.146s	sys 0.089s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32979775,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":1103,"lbm_read_time_us":16561,"lbm_reads_lt_1ms":775,"lbm_write_time_us":37621,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":5760,"thread_start_us":99,"threads_started":1,"update_count":3500}
I20260812 06:17:18.937510  1129 maintenance_manager.cc:419] P 2dc7e75f19e747669c8cb628ba0a23c2: Scheduling FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d): perf score=15.087375
I20260812 06:17:18.994071  1064 maintenance_manager.cc:643] P 2dc7e75f19e747669c8cb628ba0a23c2: FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d) complete. Timing: real 0.056s	user 0.032s	sys 0.020s Metrics: {"bytes_written":16820144,"delete_count":0,"lbm_write_time_us":25307,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:17:18.994668  1129 maintenance_manager.cc:419] P 2dc7e75f19e747669c8cb628ba0a23c2: Scheduling FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d): perf score=2.188937
I20260812 06:17:19.010265  1064 maintenance_manager.cc:643] P 2dc7e75f19e747669c8cb628ba0a23c2: FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d) complete. Timing: real 0.015s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102660,"delete_count":0,"lbm_write_time_us":3904,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:19.010826  1129 maintenance_manager.cc:419] P 2dc7e75f19e747669c8cb628ba0a23c2: Scheduling FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d): perf score=2.188937
I20260812 06:17:19.020542  1064 maintenance_manager.cc:643] P 2dc7e75f19e747669c8cb628ba0a23c2: FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d) complete. Timing: real 0.010s	user 0.003s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3622,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:19.021044  1129 maintenance_manager.cc:419] P 2dc7e75f19e747669c8cb628ba0a23c2: Scheduling MajorDeltaCompactionOp(ee564200b86c468fb85a878822eaa27d): perf score=1.000000
I20260812 06:17:19.233204  1064 maintenance_manager.cc:643] P 2dc7e75f19e747669c8cb628ba0a23c2: MajorDeltaCompactionOp(ee564200b86c468fb85a878822eaa27d) complete. Timing: real 0.212s	user 0.148s	sys 0.064s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877209,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":706,"lbm_read_time_us":14257,"lbm_reads_lt_1ms":673,"lbm_write_time_us":36283,"lbm_writes_lt_1ms":643,"mutex_wait_us":84,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":19072,"update_count":3000}
I20260812 06:17:19.233778  1129 maintenance_manager.cc:419] P 2dc7e75f19e747669c8cb628ba0a23c2: Scheduling FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d): perf score=15.087375
I20260812 06:17:19.292032  1064 maintenance_manager.cc:643] P 2dc7e75f19e747669c8cb628ba0a23c2: FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d) complete. Timing: real 0.058s	user 0.037s	sys 0.019s Metrics: {"bytes_written":16656046,"delete_count":0,"lbm_write_time_us":25773,"lbm_writes_lt_1ms":409,"reinsert_count":0,"update_count":2030}
I20260812 06:17:19.292631  1129 maintenance_manager.cc:419] P 2dc7e75f19e747669c8cb628ba0a23c2: Scheduling FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d): perf score=2.188937
I20260812 06:17:19.309860  1064 maintenance_manager.cc:643] P 2dc7e75f19e747669c8cb628ba0a23c2: FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d) complete. Timing: real 0.017s	user 0.015s	sys 0.000s Metrics: {"bytes_written":3856509,"delete_count":0,"lbm_write_time_us":6525,"lbm_writes_lt_1ms":97,"reinsert_count":0,"update_count":470}
I20260812 06:17:19.310495  1129 maintenance_manager.cc:419] P 2dc7e75f19e747669c8cb628ba0a23c2: Scheduling MajorDeltaCompactionOp(ee564200b86c468fb85a878822eaa27d): perf score=1.000000
I20260812 06:17:19.499936  1064 maintenance_manager.cc:643] P 2dc7e75f19e747669c8cb628ba0a23c2: MajorDeltaCompactionOp(ee564200b86c468fb85a878822eaa27d) complete. Timing: real 0.189s	user 0.113s	sys 0.065s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":99,"lbm_read_time_us":11018,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29974,"lbm_writes_lt_1ms":543,"mutex_wait_us":25,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11392,"update_count":2500}
I20260812 06:17:19.500613  1129 maintenance_manager.cc:419] P 2dc7e75f19e747669c8cb628ba0a23c2: Scheduling FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d): perf score=14.095187
I20260812 06:17:19.574853  1064 maintenance_manager.cc:643] P 2dc7e75f19e747669c8cb628ba0a23c2: FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d) complete. Timing: real 0.074s	user 0.030s	sys 0.028s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":25084,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:19.575374  1129 maintenance_manager.cc:419] P 2dc7e75f19e747669c8cb628ba0a23c2: Scheduling FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d): perf score=2.188937
I20260812 06:17:19.588372  1064 maintenance_manager.cc:643] P 2dc7e75f19e747669c8cb628ba0a23c2: FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d) complete. Timing: real 0.013s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4351,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:19.589964  1129 maintenance_manager.cc:419] P 2dc7e75f19e747669c8cb628ba0a23c2: Scheduling MajorDeltaCompactionOp(ee564200b86c468fb85a878822eaa27d): perf score=1.000000
I20260812 06:17:19.791509  1064 maintenance_manager.cc:643] P 2dc7e75f19e747669c8cb628ba0a23c2: MajorDeltaCompactionOp(ee564200b86c468fb85a878822eaa27d) complete. Timing: real 0.201s	user 0.133s	sys 0.059s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":931,"lbm_read_time_us":13523,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34033,"lbm_writes_lt_1ms":543,"mutex_wait_us":22,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":15872,"update_count":2500}
I20260812 06:17:19.792101  1129 maintenance_manager.cc:419] P 2dc7e75f19e747669c8cb628ba0a23c2: Scheduling FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d): perf score=14.095187
I20260812 06:17:19.857249  1064 maintenance_manager.cc:643] P 2dc7e75f19e747669c8cb628ba0a23c2: FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d) complete. Timing: real 0.065s	user 0.027s	sys 0.034s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24898,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:17:19.857847  1129 maintenance_manager.cc:419] P 2dc7e75f19e747669c8cb628ba0a23c2: Scheduling FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d): perf score=2.188937
I20260812 06:17:19.869213  1064 maintenance_manager.cc:643] P 2dc7e75f19e747669c8cb628ba0a23c2: FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d) complete. Timing: real 0.011s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4481,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:19.869704  1129 maintenance_manager.cc:419] P 2dc7e75f19e747669c8cb628ba0a23c2: Scheduling MajorDeltaCompactionOp(ee564200b86c468fb85a878822eaa27d): perf score=1.000000
I20260812 06:17:20.054442  1064 maintenance_manager.cc:643] P 2dc7e75f19e747669c8cb628ba0a23c2: MajorDeltaCompactionOp(ee564200b86c468fb85a878822eaa27d) complete. Timing: real 0.185s	user 0.125s	sys 0.055s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":530,"lbm_read_time_us":13283,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29925,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:17:20.055045  1129 maintenance_manager.cc:419] P 2dc7e75f19e747669c8cb628ba0a23c2: Scheduling FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d): perf score=11.118625
I20260812 06:17:20.112723  1064 maintenance_manager.cc:643] P 2dc7e75f19e747669c8cb628ba0a23c2: FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d) complete. Timing: real 0.058s	user 0.029s	sys 0.018s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":21578,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:17:20.113289  1129 maintenance_manager.cc:419] P 2dc7e75f19e747669c8cb628ba0a23c2: Scheduling FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d): perf score=2.188937
I20260812 06:17:20.140892  1064 maintenance_manager.cc:643] P 2dc7e75f19e747669c8cb628ba0a23c2: FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d) complete. Timing: real 0.027s	user 0.009s	sys 0.015s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6516,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:20.141460  1129 maintenance_manager.cc:419] P 2dc7e75f19e747669c8cb628ba0a23c2: Scheduling FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d): perf score=2.188937
I20260812 06:17:20.152132  1064 maintenance_manager.cc:643] P 2dc7e75f19e747669c8cb628ba0a23c2: FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3866,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:20.152724  1129 maintenance_manager.cc:419] P 2dc7e75f19e747669c8cb628ba0a23c2: Scheduling FlushMRSOp(ee564200b86c468fb85a878822eaa27d): perf score=1.000000
I20260812 06:17:20.200153  1064 maintenance_manager.cc:643] P 2dc7e75f19e747669c8cb628ba0a23c2: FlushMRSOp(ee564200b86c468fb85a878822eaa27d) complete. Timing: real 0.047s	user 0.034s	sys 0.000s Metrics: {"bytes_written":1193509,"cfile_init":1,"dirs.queue_time_us":69,"dirs.run_cpu_time_us":228,"dirs.run_wall_time_us":1634,"drs_written":1,"lbm_read_time_us":43,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1690,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:17:20.200858  1129 maintenance_manager.cc:419] P 2dc7e75f19e747669c8cb628ba0a23c2: Scheduling LogGCOp(ee564200b86c468fb85a878822eaa27d): free 124257208 bytes of WAL
I20260812 06:17:20.201085  1064 log_reader.cc:385] T ee564200b86c468fb85a878822eaa27d: removed 12 log segments from log reader
I20260812 06:17:20.201130  1064 log.cc:1079] T ee564200b86c468fb85a878822eaa27d P 2dc7e75f19e747669c8cb628ba0a23c2: Deleting log segment in path: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431121259-757-0/minicluster-data/ts-0-root/wals/ee564200b86c468fb85a878822eaa27d/wal-000000015 (ops 71-75)
I20260812 06:17:20.201159  1064 log.cc:1079] T ee564200b86c468fb85a878822eaa27d P 2dc7e75f19e747669c8cb628ba0a23c2: Deleting log segment in path: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431121259-757-0/minicluster-data/ts-0-root/wals/ee564200b86c468fb85a878822eaa27d/wal-000000016 (ops 76-80)
I20260812 06:17:20.201216  1064 log.cc:1079] T ee564200b86c468fb85a878822eaa27d P 2dc7e75f19e747669c8cb628ba0a23c2: Deleting log segment in path: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431121259-757-0/minicluster-data/ts-0-root/wals/ee564200b86c468fb85a878822eaa27d/wal-000000017 (ops 81-85)
I20260812 06:17:20.201246  1064 log.cc:1079] T ee564200b86c468fb85a878822eaa27d P 2dc7e75f19e747669c8cb628ba0a23c2: Deleting log segment in path: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431121259-757-0/minicluster-data/ts-0-root/wals/ee564200b86c468fb85a878822eaa27d/wal-000000018 (ops 86-90)
I20260812 06:17:20.201295  1064 log.cc:1079] T ee564200b86c468fb85a878822eaa27d P 2dc7e75f19e747669c8cb628ba0a23c2: Deleting log segment in path: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431121259-757-0/minicluster-data/ts-0-root/wals/ee564200b86c468fb85a878822eaa27d/wal-000000019 (ops 91-95)
I20260812 06:17:20.201350  1064 log.cc:1079] T ee564200b86c468fb85a878822eaa27d P 2dc7e75f19e747669c8cb628ba0a23c2: Deleting log segment in path: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431121259-757-0/minicluster-data/ts-0-root/wals/ee564200b86c468fb85a878822eaa27d/wal-000000020 (ops 96-100)
I20260812 06:17:20.201391  1064 log.cc:1079] T ee564200b86c468fb85a878822eaa27d P 2dc7e75f19e747669c8cb628ba0a23c2: Deleting log segment in path: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431121259-757-0/minicluster-data/ts-0-root/wals/ee564200b86c468fb85a878822eaa27d/wal-000000021 (ops 101-105)
I20260812 06:17:20.201428  1064 log.cc:1079] T ee564200b86c468fb85a878822eaa27d P 2dc7e75f19e747669c8cb628ba0a23c2: Deleting log segment in path: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431121259-757-0/minicluster-data/ts-0-root/wals/ee564200b86c468fb85a878822eaa27d/wal-000000022 (ops 106-110)
I20260812 06:17:20.201465  1064 log.cc:1079] T ee564200b86c468fb85a878822eaa27d P 2dc7e75f19e747669c8cb628ba0a23c2: Deleting log segment in path: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431121259-757-0/minicluster-data/ts-0-root/wals/ee564200b86c468fb85a878822eaa27d/wal-000000023 (ops 111-114)
I20260812 06:17:20.201502  1064 log.cc:1079] T ee564200b86c468fb85a878822eaa27d P 2dc7e75f19e747669c8cb628ba0a23c2: Deleting log segment in path: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431121259-757-0/minicluster-data/ts-0-root/wals/ee564200b86c468fb85a878822eaa27d/wal-000000024 (ops 115-119)
I20260812 06:17:20.201540  1064 log.cc:1079] T ee564200b86c468fb85a878822eaa27d P 2dc7e75f19e747669c8cb628ba0a23c2: Deleting log segment in path: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431121259-757-0/minicluster-data/ts-0-root/wals/ee564200b86c468fb85a878822eaa27d/wal-000000025 (ops 120-124)
I20260812 06:17:20.201578  1064 log.cc:1079] T ee564200b86c468fb85a878822eaa27d P 2dc7e75f19e747669c8cb628ba0a23c2: Deleting log segment in path: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431121259-757-0/minicluster-data/ts-0-root/wals/ee564200b86c468fb85a878822eaa27d/wal-000000026 (ops 125-129)
I20260812 06:17:20.231383  1064 maintenance_manager.cc:643] P 2dc7e75f19e747669c8cb628ba0a23c2: LogGCOp(ee564200b86c468fb85a878822eaa27d) complete. Timing: real 0.030s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:17:20.231882  1129 maintenance_manager.cc:419] P 2dc7e75f19e747669c8cb628ba0a23c2: Scheduling FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d): perf score=3.181125
I20260812 06:17:20.255923  1064 maintenance_manager.cc:643] P 2dc7e75f19e747669c8cb628ba0a23c2: FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d) complete. Timing: real 0.024s	user 0.017s	sys 0.001s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":8009,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:20.256426  1129 maintenance_manager.cc:419] P 2dc7e75f19e747669c8cb628ba0a23c2: Scheduling FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d): perf score=2.188937
I20260812 06:17:20.267375  1064 maintenance_manager.cc:643] P 2dc7e75f19e747669c8cb628ba0a23c2: FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4104,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:20.267967  1129 maintenance_manager.cc:419] P 2dc7e75f19e747669c8cb628ba0a23c2: Scheduling MajorDeltaCompactionOp(ee564200b86c468fb85a878822eaa27d): perf score=1.000000
I20260812 06:17:20.516570  1064 maintenance_manager.cc:643] P 2dc7e75f19e747669c8cb628ba0a23c2: MajorDeltaCompactionOp(ee564200b86c468fb85a878822eaa27d) complete. Timing: real 0.248s	user 0.162s	sys 0.076s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32979852,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":7560,"lbm_read_time_us":16587,"lbm_reads_lt_1ms":775,"lbm_write_time_us":43633,"lbm_writes_lt_1ms":743,"mutex_wait_us":2193,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":768,"thread_start_us":114,"threads_started":1,"update_count":3500}
I20260812 06:17:20.517333  1129 maintenance_manager.cc:419] P 2dc7e75f19e747669c8cb628ba0a23c2: Scheduling UndoDeltaBlockGCOp(ee564200b86c468fb85a878822eaa27d): 463 bytes on disk
I20260812 06:17:20.517989  1064 maintenance_manager.cc:643] P 2dc7e75f19e747669c8cb628ba0a23c2: UndoDeltaBlockGCOp(ee564200b86c468fb85a878822eaa27d) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":130,"lbm_reads_lt_1ms":4}
I20260812 06:17:20.518836  1129 maintenance_manager.cc:419] P 2dc7e75f19e747669c8cb628ba0a23c2: Scheduling FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d): perf score=18.063937
I20260812 06:17:20.585335  1064 maintenance_manager.cc:643] P 2dc7e75f19e747669c8cb628ba0a23c2: FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d) complete. Timing: real 0.066s	user 0.054s	sys 0.010s Metrics: {"bytes_written":20512319,"delete_count":0,"lbm_write_time_us":30161,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:20.585878  1129 maintenance_manager.cc:419] P 2dc7e75f19e747669c8cb628ba0a23c2: Scheduling FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d): perf score=2.188937
I20260812 06:17:20.602080  1064 maintenance_manager.cc:643] P 2dc7e75f19e747669c8cb628ba0a23c2: FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d) complete. Timing: real 0.016s	user 0.002s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6164,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:20.602864  1129 maintenance_manager.cc:419] P 2dc7e75f19e747669c8cb628ba0a23c2: Scheduling MajorDeltaCompactionOp(ee564200b86c468fb85a878822eaa27d): perf score=1.000000
I20260812 06:17:20.809018  1064 maintenance_manager.cc:643] P 2dc7e75f19e747669c8cb628ba0a23c2: MajorDeltaCompactionOp(ee564200b86c468fb85a878822eaa27d) complete. Timing: real 0.206s	user 0.152s	sys 0.054s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877106,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1201,"lbm_read_time_us":13308,"lbm_reads_lt_1ms":672,"lbm_write_time_us":35304,"lbm_writes_lt_1ms":643,"mutex_wait_us":386,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":32512,"update_count":3000}
I20260812 06:17:20.809755  1129 maintenance_manager.cc:419] P 2dc7e75f19e747669c8cb628ba0a23c2: Scheduling FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d): perf score=14.095187
I20260812 06:17:20.851621  1064 maintenance_manager.cc:643] P 2dc7e75f19e747669c8cb628ba0a23c2: FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d) complete. Timing: real 0.042s	user 0.025s	sys 0.015s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18515,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:20.852210  1129 maintenance_manager.cc:419] P 2dc7e75f19e747669c8cb628ba0a23c2: Scheduling FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d): perf score=2.188937
I20260812 06:17:20.863065  1064 maintenance_manager.cc:643] P 2dc7e75f19e747669c8cb628ba0a23c2: FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4098,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:20.863538  1129 maintenance_manager.cc:419] P 2dc7e75f19e747669c8cb628ba0a23c2: Scheduling MajorDeltaCompactionOp(ee564200b86c468fb85a878822eaa27d): perf score=1.000000
I20260812 06:17:21.027554  1064 maintenance_manager.cc:643] P 2dc7e75f19e747669c8cb628ba0a23c2: MajorDeltaCompactionOp(ee564200b86c468fb85a878822eaa27d) complete. Timing: real 0.164s	user 0.108s	sys 0.055s 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":1125,"lbm_read_time_us":10586,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31339,"lbm_writes_lt_1ms":543,"mutex_wait_us":323,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7552,"update_count":2500}
I20260812 06:17:21.028486  1129 maintenance_manager.cc:419] P 2dc7e75f19e747669c8cb628ba0a23c2: Scheduling FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d): perf score=10.126437
I20260812 06:17:21.060148  1064 maintenance_manager.cc:643] P 2dc7e75f19e747669c8cb628ba0a23c2: FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d) complete. Timing: real 0.031s	user 0.018s	sys 0.012s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":13893,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:21.060768  1129 maintenance_manager.cc:419] P 2dc7e75f19e747669c8cb628ba0a23c2: Scheduling FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d): perf score=2.188937
I20260812 06:17:21.077562  1064 maintenance_manager.cc:643] P 2dc7e75f19e747669c8cb628ba0a23c2: FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d) complete. Timing: real 0.017s	user 0.003s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6311,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:21.078231  1129 maintenance_manager.cc:419] P 2dc7e75f19e747669c8cb628ba0a23c2: Scheduling MajorDeltaCompactionOp(ee564200b86c468fb85a878822eaa27d): perf score=1.000000
I20260812 06:17:21.243188  1064 maintenance_manager.cc:643] P 2dc7e75f19e747669c8cb628ba0a23c2: MajorDeltaCompactionOp(ee564200b86c468fb85a878822eaa27d) complete. Timing: real 0.165s	user 0.120s	sys 0.037s 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":855,"lbm_read_time_us":9971,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26588,"lbm_writes_lt_1ms":443,"mutex_wait_us":50,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6400,"update_count":2000}
I20260812 06:17:21.243832  1129 maintenance_manager.cc:419] P 2dc7e75f19e747669c8cb628ba0a23c2: Scheduling FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d): perf score=14.095187
I20260812 06:17:21.306113  1064 maintenance_manager.cc:643] P 2dc7e75f19e747669c8cb628ba0a23c2: FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d) complete. Timing: real 0.062s	user 0.030s	sys 0.023s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":20342,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:21.306784  1129 maintenance_manager.cc:419] P 2dc7e75f19e747669c8cb628ba0a23c2: Scheduling FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d): perf score=2.188937
I20260812 06:17:21.317845  1064 maintenance_manager.cc:643] P 2dc7e75f19e747669c8cb628ba0a23c2: FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4258,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:21.318317  1129 maintenance_manager.cc:419] P 2dc7e75f19e747669c8cb628ba0a23c2: Scheduling MajorDeltaCompactionOp(ee564200b86c468fb85a878822eaa27d): perf score=1.000000
I20260812 06:17:21.518374  1064 maintenance_manager.cc:643] P 2dc7e75f19e747669c8cb628ba0a23c2: MajorDeltaCompactionOp(ee564200b86c468fb85a878822eaa27d) complete. Timing: real 0.200s	user 0.142s	sys 0.049s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":997,"lbm_read_time_us":12837,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32647,"lbm_writes_lt_1ms":543,"mutex_wait_us":27,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2816,"update_count":2500}
I20260812 06:17:21.519294  1129 maintenance_manager.cc:419] P 2dc7e75f19e747669c8cb628ba0a23c2: Scheduling FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d): perf score=14.095187
I20260812 06:17:21.578606  1064 maintenance_manager.cc:643] P 2dc7e75f19e747669c8cb628ba0a23c2: FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d) complete. Timing: real 0.059s	user 0.035s	sys 0.023s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":26181,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:17:21.579412  1129 maintenance_manager.cc:419] P 2dc7e75f19e747669c8cb628ba0a23c2: Scheduling FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d): perf score=2.188937
I20260812 06:17:21.614562  1064 maintenance_manager.cc:643] P 2dc7e75f19e747669c8cb628ba0a23c2: FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d) complete. Timing: real 0.035s	user 0.005s	sys 0.019s 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:17:21.615149  1129 maintenance_manager.cc:419] P 2dc7e75f19e747669c8cb628ba0a23c2: Scheduling FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d): perf score=2.188937
I20260812 06:17:21.626891  1064 maintenance_manager.cc:643] P 2dc7e75f19e747669c8cb628ba0a23c2: FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d) complete. Timing: real 0.012s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4635,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:21.627421  1129 maintenance_manager.cc:419] P 2dc7e75f19e747669c8cb628ba0a23c2: Scheduling FlushMRSOp(ee564200b86c468fb85a878822eaa27d): perf score=1.000000
I20260812 06:17:21.667470  1064 maintenance_manager.cc:643] P 2dc7e75f19e747669c8cb628ba0a23c2: FlushMRSOp(ee564200b86c468fb85a878822eaa27d) complete. Timing: real 0.040s	user 0.035s	sys 0.000s Metrics: {"bytes_written":1152510,"cfile_init":1,"dirs.queue_time_us":82,"dirs.run_cpu_time_us":337,"dirs.run_wall_time_us":1667,"drs_written":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1494,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:17:21.668198  1129 maintenance_manager.cc:419] P 2dc7e75f19e747669c8cb628ba0a23c2: Scheduling LogGCOp(ee564200b86c468fb85a878822eaa27d): free 112239554 bytes of WAL
I20260812 06:17:21.668438  1064 log_reader.cc:385] T ee564200b86c468fb85a878822eaa27d: removed 11 log segments from log reader
I20260812 06:17:21.668488  1064 log.cc:1079] T ee564200b86c468fb85a878822eaa27d P 2dc7e75f19e747669c8cb628ba0a23c2: Deleting log segment in path: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431121259-757-0/minicluster-data/ts-0-root/wals/ee564200b86c468fb85a878822eaa27d/wal-000000027 (ops 130-134)
I20260812 06:17:21.668519  1064 log.cc:1079] T ee564200b86c468fb85a878822eaa27d P 2dc7e75f19e747669c8cb628ba0a23c2: Deleting log segment in path: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431121259-757-0/minicluster-data/ts-0-root/wals/ee564200b86c468fb85a878822eaa27d/wal-000000028 (ops 135-139)
I20260812 06:17:21.668591  1064 log.cc:1079] T ee564200b86c468fb85a878822eaa27d P 2dc7e75f19e747669c8cb628ba0a23c2: Deleting log segment in path: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431121259-757-0/minicluster-data/ts-0-root/wals/ee564200b86c468fb85a878822eaa27d/wal-000000029 (ops 140-144)
I20260812 06:17:21.668632  1064 log.cc:1079] T ee564200b86c468fb85a878822eaa27d P 2dc7e75f19e747669c8cb628ba0a23c2: Deleting log segment in path: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431121259-757-0/minicluster-data/ts-0-root/wals/ee564200b86c468fb85a878822eaa27d/wal-000000030 (ops 145-148)
I20260812 06:17:21.668687  1064 log.cc:1079] T ee564200b86c468fb85a878822eaa27d P 2dc7e75f19e747669c8cb628ba0a23c2: Deleting log segment in path: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431121259-757-0/minicluster-data/ts-0-root/wals/ee564200b86c468fb85a878822eaa27d/wal-000000031 (ops 149-153)
I20260812 06:17:21.668735  1064 log.cc:1079] T ee564200b86c468fb85a878822eaa27d P 2dc7e75f19e747669c8cb628ba0a23c2: Deleting log segment in path: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431121259-757-0/minicluster-data/ts-0-root/wals/ee564200b86c468fb85a878822eaa27d/wal-000000032 (ops 154-158)
I20260812 06:17:21.668777  1064 log.cc:1079] T ee564200b86c468fb85a878822eaa27d P 2dc7e75f19e747669c8cb628ba0a23c2: Deleting log segment in path: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431121259-757-0/minicluster-data/ts-0-root/wals/ee564200b86c468fb85a878822eaa27d/wal-000000033 (ops 159-163)
I20260812 06:17:21.668836  1064 log.cc:1079] T ee564200b86c468fb85a878822eaa27d P 2dc7e75f19e747669c8cb628ba0a23c2: Deleting log segment in path: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431121259-757-0/minicluster-data/ts-0-root/wals/ee564200b86c468fb85a878822eaa27d/wal-000000034 (ops 164-168)
I20260812 06:17:21.668881  1064 log.cc:1079] T ee564200b86c468fb85a878822eaa27d P 2dc7e75f19e747669c8cb628ba0a23c2: Deleting log segment in path: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431121259-757-0/minicluster-data/ts-0-root/wals/ee564200b86c468fb85a878822eaa27d/wal-000000035 (ops 169-173)
I20260812 06:17:21.668922  1064 log.cc:1079] T ee564200b86c468fb85a878822eaa27d P 2dc7e75f19e747669c8cb628ba0a23c2: Deleting log segment in path: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431121259-757-0/minicluster-data/ts-0-root/wals/ee564200b86c468fb85a878822eaa27d/wal-000000036 (ops 174-178)
I20260812 06:17:21.668964  1064 log.cc:1079] T ee564200b86c468fb85a878822eaa27d P 2dc7e75f19e747669c8cb628ba0a23c2: Deleting log segment in path: /tmp/dist-test-taskyQkAgs/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515431121259-757-0/minicluster-data/ts-0-root/wals/ee564200b86c468fb85a878822eaa27d/wal-000000037 (ops 179-183)
I20260812 06:17:21.695914  1064 maintenance_manager.cc:643] P 2dc7e75f19e747669c8cb628ba0a23c2: LogGCOp(ee564200b86c468fb85a878822eaa27d) complete. Timing: real 0.028s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:17:21.696604  1129 maintenance_manager.cc:419] P 2dc7e75f19e747669c8cb628ba0a23c2: Scheduling UndoDeltaBlockGCOp(ee564200b86c468fb85a878822eaa27d): 447 bytes on disk
I20260812 06:17:21.697278  1064 maintenance_manager.cc:643] P 2dc7e75f19e747669c8cb628ba0a23c2: UndoDeltaBlockGCOp(ee564200b86c468fb85a878822eaa27d) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":73,"lbm_reads_lt_1ms":4}
I20260812 06:17:21.698027  1129 maintenance_manager.cc:419] P 2dc7e75f19e747669c8cb628ba0a23c2: Scheduling FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d): perf score=3.181125
I20260812 06:17:21.714480  1064 maintenance_manager.cc:643] P 2dc7e75f19e747669c8cb628ba0a23c2: FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d) complete. Timing: real 0.016s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4822,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:21.715021  1129 maintenance_manager.cc:419] P 2dc7e75f19e747669c8cb628ba0a23c2: Scheduling FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d): perf score=2.188937
I20260812 06:17:21.725692  1064 maintenance_manager.cc:643] P 2dc7e75f19e747669c8cb628ba0a23c2: FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d) complete. Timing: real 0.010s	user 0.005s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3926,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:21.726267  1129 maintenance_manager.cc:419] P 2dc7e75f19e747669c8cb628ba0a23c2: Scheduling MajorDeltaCompactionOp(ee564200b86c468fb85a878822eaa27d): perf score=1.000000
I20260812 06:17:22.000970  1064 maintenance_manager.cc:643] P 2dc7e75f19e747669c8cb628ba0a23c2: MajorDeltaCompactionOp(ee564200b86c468fb85a878822eaa27d) complete. Timing: real 0.274s	user 0.201s	sys 0.073s Metrics: {"cfile_cache_miss":835,"cfile_cache_miss_bytes":37082273,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":583,"lbm_read_time_us":18953,"lbm_reads_lt_1ms":875,"lbm_write_time_us":47431,"lbm_writes_lt_1ms":843,"mutex_wait_us":26,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":22528,"thread_start_us":83,"threads_started":1,"update_count":4000}
I20260812 06:17:22.001843  1129 maintenance_manager.cc:419] P 2dc7e75f19e747669c8cb628ba0a23c2: Scheduling FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d): perf score=18.063937
I20260812 06:17:22.066061  1064 maintenance_manager.cc:643] P 2dc7e75f19e747669c8cb628ba0a23c2: FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d) complete. Timing: real 0.064s	user 0.047s	sys 0.015s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":29033,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:22.066702  1129 maintenance_manager.cc:419] P 2dc7e75f19e747669c8cb628ba0a23c2: Scheduling FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d): perf score=2.188937
I20260812 06:17:22.080984  1064 maintenance_manager.cc:643] P 2dc7e75f19e747669c8cb628ba0a23c2: FlushDeltaMemStoresOp(ee564200b86c468fb85a878822eaa27d) complete. Timing: real 0.014s	user 0.002s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5175,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:22.081535  1129 maintenance_manager.cc:419] P 2dc7e75f19e747669c8cb628ba0a23c2: Scheduling MajorDeltaCompactionOp(ee564200b86c468fb85a878822eaa27d): perf score=1.000000
I20260812 06:17:22.102108   757 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.181s	user 1.874s	sys 0.191s
I20260812 06:17:22.155808   757 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.053s	user 0.001s	sys 0.000s
I20260812 06:17:22.156365   757 tablet_server.cc:179] TabletServer@127.0.189.65:0 shutting down...
I20260812 06:17:22.235424  1064 maintenance_manager.cc:643] P 2dc7e75f19e747669c8cb628ba0a23c2: MajorDeltaCompactionOp(ee564200b86c468fb85a878822eaa27d) complete. Timing: real 0.154s	user 0.122s	sys 0.031s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877103,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":302,"lbm_read_time_us":11184,"lbm_reads_lt_1ms":668,"lbm_write_time_us":30324,"lbm_writes_lt_1ms":643,"mutex_wait_us":49,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":15488,"update_count":3000}
I20260812 06:17:22.236227   757 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:22.236590   757 tablet_replica.cc:333] T ee564200b86c468fb85a878822eaa27d P 2dc7e75f19e747669c8cb628ba0a23c2: stopping tablet replica
I20260812 06:17:22.236752   757 raft_consensus.cc:2243] T ee564200b86c468fb85a878822eaa27d P 2dc7e75f19e747669c8cb628ba0a23c2 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:22.236971   757 raft_consensus.cc:2272] T ee564200b86c468fb85a878822eaa27d P 2dc7e75f19e747669c8cb628ba0a23c2 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:22.242908   757 tablet_server.cc:196] TabletServer@127.0.189.65:0 shutdown complete.
I20260812 06:17:22.292590   757 master.cc:562] Master@127.0.189.126:38545 shutting down...
I20260812 06:17:22.296876   757 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 9c0ced44706d42c4b08f9d0f509ceffb [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:22.297132   757 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 9c0ced44706d42c4b08f9d0f509ceffb [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:22.297231   757 tablet_replica.cc:333] T 00000000000000000000000000000000 P 9c0ced44706d42c4b08f9d0f509ceffb: stopping tablet replica
I20260812 06:17:22.309967   757 master.cc:584] Master@127.0.189.126:38545 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5719 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11268 ms total)

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