[==========] 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:19:26.578110 30521 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.29.206.126:33005
I20260812 06:19:26.579306 30521 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:19:26.579977 30521 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:26.587385 30529 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:26.587520 30521 server_base.cc:1061] running on GCE node
W20260812 06:19:26.587415 30527 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:19:26.587700 30526 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:19:26.588261 30521 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:26.588416 30521 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:19:26.588502 30521 hybrid_clock.cc:648] HybridClock initialized: now 1786515566588490 us; error 0 us; skew 500 ppm
I20260812 06:19:26.590755 30521 webserver.cc:533] Webserver started at http://127.29.206.126:40235/ using document root <none> and password file <none>
I20260812 06:19:26.591423 30521 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:26.591542 30521 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:26.591835 30521 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:26.593748 30521 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566566673-30521-0/minicluster-data/master-0-root/instance:
uuid: "0ef3b57aef9c403780cb8d9be88ca044"
format_stamp: "Formatted at 2026-08-12 06:19:26 on dist-test-slave-5l3k"
I20260812 06:19:26.597949 30521 fs_manager.cc:696] Time spent creating directory manager: real 0.004s	user 0.003s	sys 0.003s
I20260812 06:19:26.600641 30535 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:19:26.601840 30521 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:26.602016 30521 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566566673-30521-0/minicluster-data/master-0-root
uuid: "0ef3b57aef9c403780cb8d9be88ca044"
format_stamp: "Formatted at 2026-08-12 06:19:26 on dist-test-slave-5l3k"
I20260812 06:19:26.602185 30521 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566566673-30521-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566566673-30521-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566566673-30521-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:19:26.636690 30521 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:26.637501 30521 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:19:26.637750 30521 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:26.646849 30597 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.29.206.126:33005 every 8 connection(s)
I20260812 06:19:26.646845 30521 rpc_server.cc:307] RPC server started. Bound to: 127.29.206.126:33005
I20260812 06:19:26.649428 30598 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:19:26.655543 30598 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 0ef3b57aef9c403780cb8d9be88ca044: Bootstrap starting.
I20260812 06:19:26.658178 30598 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 0ef3b57aef9c403780cb8d9be88ca044: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:26.659332 30598 log.cc:826] T 00000000000000000000000000000000 P 0ef3b57aef9c403780cb8d9be88ca044: Log is configured to *not* fsync() on all Append() calls
I20260812 06:19:26.661291 30598 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 0ef3b57aef9c403780cb8d9be88ca044: No bootstrap required, opened a new log
I20260812 06:19:26.664443 30598 raft_consensus.cc:359] T 00000000000000000000000000000000 P 0ef3b57aef9c403780cb8d9be88ca044 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0ef3b57aef9c403780cb8d9be88ca044" member_type: VOTER }
I20260812 06:19:26.664638 30598 raft_consensus.cc:385] T 00000000000000000000000000000000 P 0ef3b57aef9c403780cb8d9be88ca044 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:26.664733 30598 raft_consensus.cc:740] T 00000000000000000000000000000000 P 0ef3b57aef9c403780cb8d9be88ca044 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 0ef3b57aef9c403780cb8d9be88ca044, State: Initialized, Role: FOLLOWER
I20260812 06:19:26.665380 30598 consensus_queue.cc:260] T 00000000000000000000000000000000 P 0ef3b57aef9c403780cb8d9be88ca044 [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: "0ef3b57aef9c403780cb8d9be88ca044" member_type: VOTER }
I20260812 06:19:26.665525 30598 raft_consensus.cc:399] T 00000000000000000000000000000000 P 0ef3b57aef9c403780cb8d9be88ca044 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:26.665602 30598 raft_consensus.cc:493] T 00000000000000000000000000000000 P 0ef3b57aef9c403780cb8d9be88ca044 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:26.665729 30598 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 0ef3b57aef9c403780cb8d9be88ca044 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:26.666719 30598 raft_consensus.cc:515] T 00000000000000000000000000000000 P 0ef3b57aef9c403780cb8d9be88ca044 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0ef3b57aef9c403780cb8d9be88ca044" member_type: VOTER }
I20260812 06:19:26.667277 30598 leader_election.cc:304] T 00000000000000000000000000000000 P 0ef3b57aef9c403780cb8d9be88ca044 [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: 0ef3b57aef9c403780cb8d9be88ca044; no voters: 
I20260812 06:19:26.667649 30598 leader_election.cc:290] T 00000000000000000000000000000000 P 0ef3b57aef9c403780cb8d9be88ca044 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:26.667847 30601 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 0ef3b57aef9c403780cb8d9be88ca044 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:26.668236 30601 raft_consensus.cc:697] T 00000000000000000000000000000000 P 0ef3b57aef9c403780cb8d9be88ca044 [term 1 LEADER]: Becoming Leader. State: Replica: 0ef3b57aef9c403780cb8d9be88ca044, State: Running, Role: LEADER
I20260812 06:19:26.668743 30601 consensus_queue.cc:237] T 00000000000000000000000000000000 P 0ef3b57aef9c403780cb8d9be88ca044 [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: "0ef3b57aef9c403780cb8d9be88ca044" member_type: VOTER }
I20260812 06:19:26.668807 30598 sys_catalog.cc:565] T 00000000000000000000000000000000 P 0ef3b57aef9c403780cb8d9be88ca044 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:26.671190 30602 sys_catalog.cc:455] T 00000000000000000000000000000000 P 0ef3b57aef9c403780cb8d9be88ca044 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "0ef3b57aef9c403780cb8d9be88ca044" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0ef3b57aef9c403780cb8d9be88ca044" member_type: VOTER } }
I20260812 06:19:26.671335 30602 sys_catalog.cc:458] T 00000000000000000000000000000000 P 0ef3b57aef9c403780cb8d9be88ca044 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:26.671399 30521 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:26.671600 30603 sys_catalog.cc:455] T 00000000000000000000000000000000 P 0ef3b57aef9c403780cb8d9be88ca044 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 0ef3b57aef9c403780cb8d9be88ca044. Latest consensus state: current_term: 1 leader_uuid: "0ef3b57aef9c403780cb8d9be88ca044" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "0ef3b57aef9c403780cb8d9be88ca044" member_type: VOTER } }
I20260812 06:19:26.671689 30603 sys_catalog.cc:458] T 00000000000000000000000000000000 P 0ef3b57aef9c403780cb8d9be88ca044 [sys.catalog]: This master's current role is: LEADER
W20260812 06:19:26.673882 30618 catalog_manager.cc:1594] T 00000000000000000000000000000000 P 0ef3b57aef9c403780cb8d9be88ca044: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:19:26.673965 30618 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:19:26.674067 30619 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:26.674979 30619 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:26.680747 30619 catalog_manager.cc:1383] Generated new cluster ID: f40d0d1d449a4f85b4d257d42f8303d5
I20260812 06:19:26.680851 30619 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:26.703047 30619 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:26.704401 30619 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:26.712455 30619 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 0ef3b57aef9c403780cb8d9be88ca044: Generated new TSK 0
I20260812 06:19:26.713361 30619 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:26.736901 30521 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:26.740129 30623 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:19:26.740116 30624 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:19:26.740305 30521 server_base.cc:1061] running on GCE node
W20260812 06:19:26.740466 30627 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:26.740760 30521 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:26.740842 30521 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:19:26.740871 30521 hybrid_clock.cc:648] HybridClock initialized: now 1786515566740870 us; error 0 us; skew 500 ppm
I20260812 06:19:26.741956 30521 webserver.cc:533] Webserver started at http://127.29.206.65:45403/ using document root <none> and password file <none>
I20260812 06:19:26.742166 30521 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:26.742245 30521 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:26.742331 30521 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:26.742820 30521 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566566673-30521-0/minicluster-data/ts-0-root/instance:
uuid: "1403e589655d45728c3f720f304b886e"
format_stamp: "Formatted at 2026-08-12 06:19:26 on dist-test-slave-5l3k"
I20260812 06:19:26.744519 30521 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:19:26.745695 30633 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:19:26.745954 30521 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:19:26.746040 30521 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566566673-30521-0/minicluster-data/ts-0-root
uuid: "1403e589655d45728c3f720f304b886e"
format_stamp: "Formatted at 2026-08-12 06:19:26 on dist-test-slave-5l3k"
I20260812 06:19:26.746145 30521 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566566673-30521-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566566673-30521-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566566673-30521-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:19:26.755378 30521 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:26.755916 30521 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:26.756469 30521 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:26.757417 30521 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:26.757472 30521 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:26.757546 30521 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:26.757594 30521 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:26.764880 30521 rpc_server.cc:307] RPC server started. Bound to: 127.29.206.65:37271
I20260812 06:19:26.764916 30706 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.29.206.65:37271 every 8 connection(s)
I20260812 06:19:26.779645 30707 heartbeater.cc:344] Connected to a master server at 127.29.206.126:33005
I20260812 06:19:26.779932 30707 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:26.780435 30707 heartbeater.cc:507] Master 127.29.206.126:33005 requested a full tablet report, sending...
I20260812 06:19:26.781957 30555 ts_manager.cc:194] Registered new tserver with Master: 1403e589655d45728c3f720f304b886e (127.29.206.65:37271)
I20260812 06:19:26.782608 30521 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.016960259s
I20260812 06:19:26.783511 30555 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:50096
I20260812 06:19:26.792941 30555 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:50112:
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:19:26.808319 30664 tablet_service.cc:1511] Processing CreateTablet for tablet 5fcfbf0d13a64b0a9a25e15901324682 (DEFAULT_TABLE table=heavy-update-compaction-test [id=0241b5d177214ff7ab8fcbcb4a895f93]), partition=
I20260812 06:19:26.808873 30664 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 5fcfbf0d13a64b0a9a25e15901324682. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:26.811966 30723 tablet_bootstrap.cc:492] T 5fcfbf0d13a64b0a9a25e15901324682 P 1403e589655d45728c3f720f304b886e: Bootstrap starting.
I20260812 06:19:26.813081 30723 tablet_bootstrap.cc:654] T 5fcfbf0d13a64b0a9a25e15901324682 P 1403e589655d45728c3f720f304b886e: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:26.815061 30723 tablet_bootstrap.cc:492] T 5fcfbf0d13a64b0a9a25e15901324682 P 1403e589655d45728c3f720f304b886e: No bootstrap required, opened a new log
I20260812 06:19:26.815199 30723 ts_tablet_manager.cc:1403] T 5fcfbf0d13a64b0a9a25e15901324682 P 1403e589655d45728c3f720f304b886e: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:19:26.815865 30723 raft_consensus.cc:359] T 5fcfbf0d13a64b0a9a25e15901324682 P 1403e589655d45728c3f720f304b886e [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1403e589655d45728c3f720f304b886e" member_type: VOTER last_known_addr { host: "127.29.206.65" port: 37271 } }
I20260812 06:19:26.816085 30723 raft_consensus.cc:385] T 5fcfbf0d13a64b0a9a25e15901324682 P 1403e589655d45728c3f720f304b886e [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:26.816146 30723 raft_consensus.cc:740] T 5fcfbf0d13a64b0a9a25e15901324682 P 1403e589655d45728c3f720f304b886e [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 1403e589655d45728c3f720f304b886e, State: Initialized, Role: FOLLOWER
I20260812 06:19:26.816295 30723 consensus_queue.cc:260] T 5fcfbf0d13a64b0a9a25e15901324682 P 1403e589655d45728c3f720f304b886e [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: "1403e589655d45728c3f720f304b886e" member_type: VOTER last_known_addr { host: "127.29.206.65" port: 37271 } }
I20260812 06:19:26.816391 30723 raft_consensus.cc:399] T 5fcfbf0d13a64b0a9a25e15901324682 P 1403e589655d45728c3f720f304b886e [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:26.816445 30723 raft_consensus.cc:493] T 5fcfbf0d13a64b0a9a25e15901324682 P 1403e589655d45728c3f720f304b886e [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:26.816509 30723 raft_consensus.cc:3060] T 5fcfbf0d13a64b0a9a25e15901324682 P 1403e589655d45728c3f720f304b886e [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:26.817324 30723 raft_consensus.cc:515] T 5fcfbf0d13a64b0a9a25e15901324682 P 1403e589655d45728c3f720f304b886e [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1403e589655d45728c3f720f304b886e" member_type: VOTER last_known_addr { host: "127.29.206.65" port: 37271 } }
I20260812 06:19:26.817451 30723 leader_election.cc:304] T 5fcfbf0d13a64b0a9a25e15901324682 P 1403e589655d45728c3f720f304b886e [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: 1403e589655d45728c3f720f304b886e; no voters: 
I20260812 06:19:26.817792 30723 leader_election.cc:290] T 5fcfbf0d13a64b0a9a25e15901324682 P 1403e589655d45728c3f720f304b886e [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:26.817909 30725 raft_consensus.cc:2804] T 5fcfbf0d13a64b0a9a25e15901324682 P 1403e589655d45728c3f720f304b886e [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:26.818181 30725 raft_consensus.cc:697] T 5fcfbf0d13a64b0a9a25e15901324682 P 1403e589655d45728c3f720f304b886e [term 1 LEADER]: Becoming Leader. State: Replica: 1403e589655d45728c3f720f304b886e, State: Running, Role: LEADER
I20260812 06:19:26.818202 30723 ts_tablet_manager.cc:1434] T 5fcfbf0d13a64b0a9a25e15901324682 P 1403e589655d45728c3f720f304b886e: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:19:26.818403 30707 heartbeater.cc:499] Master 127.29.206.126:33005 was elected leader, sending a full tablet report...
I20260812 06:19:26.818430 30725 consensus_queue.cc:237] T 5fcfbf0d13a64b0a9a25e15901324682 P 1403e589655d45728c3f720f304b886e [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: "1403e589655d45728c3f720f304b886e" member_type: VOTER last_known_addr { host: "127.29.206.65" port: 37271 } }
I20260812 06:19:26.821658 30554 catalog_manager.cc:5719] T 5fcfbf0d13a64b0a9a25e15901324682 P 1403e589655d45728c3f720f304b886e reported cstate change: term changed from 0 to 1, leader changed from <none> to 1403e589655d45728c3f720f304b886e (127.29.206.65). New cstate: current_term: 1 leader_uuid: "1403e589655d45728c3f720f304b886e" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "1403e589655d45728c3f720f304b886e" member_type: VOTER last_known_addr { host: "127.29.206.65" port: 37271 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:26.916587 30521 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.087s	user 0.026s	sys 0.017s
I20260812 06:19:27.016287 30708 maintenance_manager.cc:419] P 1403e589655d45728c3f720f304b886e: Scheduling FlushMRSOp(5fcfbf0d13a64b0a9a25e15901324682): perf score=11.117440
I20260812 06:19:27.153270 30639 maintenance_manager.cc:643] P 1403e589655d45728c3f720f304b886e: FlushMRSOp(5fcfbf0d13a64b0a9a25e15901324682) complete. Timing: real 0.137s	user 0.106s	sys 0.024s Metrics: {"bytes_written":8205078,"cfile_init":1,"compiler_manager_pool.queue_time_us":916,"delete_count":0,"dirs.queue_time_us":42,"dirs.run_cpu_time_us":274,"dirs.run_wall_time_us":1257,"drs_written":1,"lbm_read_time_us":75,"lbm_reads_lt_1ms":4,"lbm_write_time_us":32663,"lbm_writes_lt_1ms":557,"peak_mem_usage":0,"reinsert_count":0,"rows_written":103,"thread_start_us":217,"threads_started":1,"update_count":1000}
I20260812 06:19:27.154373 30708 maintenance_manager.cc:419] P 1403e589655d45728c3f720f304b886e: Scheduling MajorDeltaCompactionOp(5fcfbf0d13a64b0a9a25e15901324682): perf score=1.000000
I20260812 06:19:27.248142 30639 maintenance_manager.cc:643] P 1403e589655d45728c3f720f304b886e: MajorDeltaCompactionOp(5fcfbf0d13a64b0a9a25e15901324682) complete. Timing: real 0.094s	user 0.074s	sys 0.017s Metrics: {"cfile_cache_miss":231,"cfile_cache_miss_bytes":12426369,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":52,"lbm_read_time_us":5212,"lbm_reads_lt_1ms":263,"lbm_write_time_us":16745,"lbm_writes_lt_1ms":243,"peak_mem_usage":25836184,"reinsert_count":0,"thread_start_us":276,"threads_started":5,"update_count":1000}
I20260812 06:19:27.250113 30708 maintenance_manager.cc:419] P 1403e589655d45728c3f720f304b886e: Scheduling LogGCOp(5fcfbf0d13a64b0a9a25e15901324682): free 8725963 bytes of WAL
I20260812 06:19:27.250554 30639 log_reader.cc:385] T 5fcfbf0d13a64b0a9a25e15901324682: removed 1 log segments from log reader
I20260812 06:19:27.250687 30639 log.cc:1079] T 5fcfbf0d13a64b0a9a25e15901324682 P 1403e589655d45728c3f720f304b886e: Deleting log segment in path: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566566673-30521-0/minicluster-data/ts-0-root/wals/5fcfbf0d13a64b0a9a25e15901324682/wal-000000001 (ops 1-6)
I20260812 06:19:27.253188 30639 maintenance_manager.cc:643] P 1403e589655d45728c3f720f304b886e: LogGCOp(5fcfbf0d13a64b0a9a25e15901324682) complete. Timing: real 0.003s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:19:27.253616 30708 maintenance_manager.cc:419] P 1403e589655d45728c3f720f304b886e: Scheduling UndoDeltaBlockGCOp(5fcfbf0d13a64b0a9a25e15901324682): 12308960 bytes on disk
I20260812 06:19:27.254148 30639 maintenance_manager.cc:643] P 1403e589655d45728c3f720f304b886e: UndoDeltaBlockGCOp(5fcfbf0d13a64b0a9a25e15901324682) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4}
I20260812 06:19:27.254767 30708 maintenance_manager.cc:419] P 1403e589655d45728c3f720f304b886e: Scheduling FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682): perf score=7.149875
I20260812 06:19:27.291286 30639 maintenance_manager.cc:643] P 1403e589655d45728c3f720f304b886e: FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682) complete. Timing: real 0.036s	user 0.030s	sys 0.004s Metrics: {"bytes_written":8615323,"delete_count":0,"lbm_write_time_us":13963,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:19:27.291807 30708 maintenance_manager.cc:419] P 1403e589655d45728c3f720f304b886e: Scheduling FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682): perf score=2.188937
I20260812 06:19:27.302671 30639 maintenance_manager.cc:643] P 1403e589655d45728c3f720f304b886e: FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682) complete. Timing: real 0.011s	user 0.003s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4113,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:27.303392 30708 maintenance_manager.cc:419] P 1403e589655d45728c3f720f304b886e: Scheduling MajorDeltaCompactionOp(5fcfbf0d13a64b0a9a25e15901324682): perf score=1.000000
I20260812 06:19:27.422729 30639 maintenance_manager.cc:643] P 1403e589655d45728c3f720f304b886e: MajorDeltaCompactionOp(5fcfbf0d13a64b0a9a25e15901324682) complete. Timing: real 0.119s	user 0.086s	sys 0.032s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16528891,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":826,"lbm_read_time_us":9005,"lbm_reads_lt_1ms":372,"lbm_write_time_us":20684,"lbm_writes_lt_1ms":343,"peak_mem_usage":38262756,"reinsert_count":0,"update_count":1500}
I20260812 06:19:27.423425 30708 maintenance_manager.cc:419] P 1403e589655d45728c3f720f304b886e: Scheduling FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682): perf score=7.149875
I20260812 06:19:27.452858 30639 maintenance_manager.cc:643] P 1403e589655d45728c3f720f304b886e: FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682) complete. Timing: real 0.029s	user 0.015s	sys 0.012s Metrics: {"bytes_written":8615323,"delete_count":0,"lbm_write_time_us":12057,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":212,"reinsert_count":0,"update_count":1050}
I20260812 06:19:27.453440 30708 maintenance_manager.cc:419] P 1403e589655d45728c3f720f304b886e: Scheduling FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682): perf score=2.188937
I20260812 06:19:27.471594 30639 maintenance_manager.cc:643] P 1403e589655d45728c3f720f304b886e: FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682) complete. Timing: real 0.018s	user 0.008s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5419,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:27.472141 30708 maintenance_manager.cc:419] P 1403e589655d45728c3f720f304b886e: Scheduling MajorDeltaCompactionOp(5fcfbf0d13a64b0a9a25e15901324682): perf score=1.000000
I20260812 06:19:27.578306 30639 maintenance_manager.cc:643] P 1403e589655d45728c3f720f304b886e: MajorDeltaCompactionOp(5fcfbf0d13a64b0a9a25e15901324682) complete. Timing: real 0.106s	user 0.080s	sys 0.026s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16528891,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":220,"lbm_read_time_us":6306,"lbm_reads_lt_1ms":364,"lbm_write_time_us":19669,"lbm_writes_lt_1ms":343,"mutex_wait_us":34,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":156544,"update_count":1500}
I20260812 06:19:27.579005 30708 maintenance_manager.cc:419] P 1403e589655d45728c3f720f304b886e: Scheduling FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682): perf score=10.126437
I20260812 06:19:27.624300 30639 maintenance_manager.cc:643] P 1403e589655d45728c3f720f304b886e: FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682) complete. Timing: real 0.045s	user 0.032s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":20126,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:27.624867 30708 maintenance_manager.cc:419] P 1403e589655d45728c3f720f304b886e: Scheduling FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682): perf score=2.188937
I20260812 06:19:27.636369 30639 maintenance_manager.cc:643] P 1403e589655d45728c3f720f304b886e: FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4009,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:27.636909 30708 maintenance_manager.cc:419] P 1403e589655d45728c3f720f304b886e: Scheduling MajorDeltaCompactionOp(5fcfbf0d13a64b0a9a25e15901324682): perf score=1.000000
I20260812 06:19:27.770368 30639 maintenance_manager.cc:643] P 1403e589655d45728c3f720f304b886e: MajorDeltaCompactionOp(5fcfbf0d13a64b0a9a25e15901324682) complete. Timing: real 0.133s	user 0.097s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1195,"lbm_read_time_us":10343,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24766,"lbm_writes_lt_1ms":443,"mutex_wait_us":301,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":22784,"update_count":2000}
I20260812 06:19:27.771102 30708 maintenance_manager.cc:419] P 1403e589655d45728c3f720f304b886e: Scheduling FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682): perf score=10.126437
I20260812 06:19:27.827040 30639 maintenance_manager.cc:643] P 1403e589655d45728c3f720f304b886e: FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682) complete. Timing: real 0.056s	user 0.033s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17261,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:27.827710 30708 maintenance_manager.cc:419] P 1403e589655d45728c3f720f304b886e: Scheduling FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682): perf score=2.188937
I20260812 06:19:27.840297 30639 maintenance_manager.cc:643] P 1403e589655d45728c3f720f304b886e: FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682) complete. Timing: real 0.012s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4747,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:27.840910 30708 maintenance_manager.cc:419] P 1403e589655d45728c3f720f304b886e: Scheduling MajorDeltaCompactionOp(5fcfbf0d13a64b0a9a25e15901324682): perf score=1.000000
I20260812 06:19:27.992466 30639 maintenance_manager.cc:643] P 1403e589655d45728c3f720f304b886e: MajorDeltaCompactionOp(5fcfbf0d13a64b0a9a25e15901324682) complete. Timing: real 0.151s	user 0.102s	sys 0.047s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1182,"lbm_read_time_us":11038,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24746,"lbm_writes_lt_1ms":443,"mutex_wait_us":281,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:27.993178 30708 maintenance_manager.cc:419] P 1403e589655d45728c3f720f304b886e: Scheduling FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682): perf score=10.126437
I20260812 06:19:28.030467 30639 maintenance_manager.cc:643] P 1403e589655d45728c3f720f304b886e: FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682) complete. Timing: real 0.037s	user 0.025s	sys 0.009s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":15662,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:28.031267 30708 maintenance_manager.cc:419] P 1403e589655d45728c3f720f304b886e: Scheduling MajorDeltaCompactionOp(5fcfbf0d13a64b0a9a25e15901324682): perf score=1.000000
I20260812 06:19:28.142033 30639 maintenance_manager.cc:643] P 1403e589655d45728c3f720f304b886e: MajorDeltaCompactionOp(5fcfbf0d13a64b0a9a25e15901324682) complete. Timing: real 0.111s	user 0.094s	sys 0.016s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16528783,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":853,"lbm_read_time_us":7387,"lbm_reads_lt_1ms":363,"lbm_write_time_us":19786,"lbm_writes_lt_1ms":343,"mutex_wait_us":18,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":8192,"update_count":1500}
I20260812 06:19:28.142660 30708 maintenance_manager.cc:419] P 1403e589655d45728c3f720f304b886e: Scheduling FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682): perf score=10.126437
I20260812 06:19:28.191684 30639 maintenance_manager.cc:643] P 1403e589655d45728c3f720f304b886e: FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682) complete. Timing: real 0.049s	user 0.034s	sys 0.004s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17281,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:28.192299 30708 maintenance_manager.cc:419] P 1403e589655d45728c3f720f304b886e: Scheduling FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682): perf score=2.188937
I20260812 06:19:28.203495 30639 maintenance_manager.cc:643] P 1403e589655d45728c3f720f304b886e: FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3936,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:28.204087 30708 maintenance_manager.cc:419] P 1403e589655d45728c3f720f304b886e: Scheduling MajorDeltaCompactionOp(5fcfbf0d13a64b0a9a25e15901324682): perf score=1.000000
I20260812 06:19:28.329176 30639 maintenance_manager.cc:643] P 1403e589655d45728c3f720f304b886e: MajorDeltaCompactionOp(5fcfbf0d13a64b0a9a25e15901324682) complete. Timing: real 0.125s	user 0.105s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":304,"lbm_read_time_us":9729,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22801,"lbm_writes_lt_1ms":443,"mutex_wait_us":80,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:28.329811 30708 maintenance_manager.cc:419] P 1403e589655d45728c3f720f304b886e: Scheduling FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682): perf score=10.126437
I20260812 06:19:28.380054 30639 maintenance_manager.cc:643] P 1403e589655d45728c3f720f304b886e: FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682) complete. Timing: real 0.050s	user 0.024s	sys 0.025s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18721,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:28.380640 30708 maintenance_manager.cc:419] P 1403e589655d45728c3f720f304b886e: Scheduling FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682): perf score=2.188937
I20260812 06:19:28.391449 30639 maintenance_manager.cc:643] P 1403e589655d45728c3f720f304b886e: FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682) complete. Timing: real 0.011s	user 0.004s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4155,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:28.391918 30708 maintenance_manager.cc:419] P 1403e589655d45728c3f720f304b886e: Scheduling MajorDeltaCompactionOp(5fcfbf0d13a64b0a9a25e15901324682): perf score=1.000000
I20260812 06:19:28.549309 30639 maintenance_manager.cc:643] P 1403e589655d45728c3f720f304b886e: MajorDeltaCompactionOp(5fcfbf0d13a64b0a9a25e15901324682) complete. Timing: real 0.157s	user 0.121s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":356,"lbm_read_time_us":11242,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24539,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:19:28.550192 30708 maintenance_manager.cc:419] P 1403e589655d45728c3f720f304b886e: Scheduling FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682): perf score=10.126437
I20260812 06:19:28.596946 30639 maintenance_manager.cc:643] P 1403e589655d45728c3f720f304b886e: FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682) complete. Timing: real 0.047s	user 0.023s	sys 0.009s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14716,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:28.597591 30708 maintenance_manager.cc:419] P 1403e589655d45728c3f720f304b886e: Scheduling FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682): perf score=2.188937
I20260812 06:19:28.614353 30639 maintenance_manager.cc:643] P 1403e589655d45728c3f720f304b886e: FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682) complete. Timing: real 0.017s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5973,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:28.615012 30708 maintenance_manager.cc:419] P 1403e589655d45728c3f720f304b886e: Scheduling FlushMRSOp(5fcfbf0d13a64b0a9a25e15901324682): perf score=1.000000
I20260812 06:19:28.646721 30639 maintenance_manager.cc:643] P 1403e589655d45728c3f720f304b886e: FlushMRSOp(5fcfbf0d13a64b0a9a25e15901324682) complete. Timing: real 0.032s	user 0.031s	sys 0.000s Metrics: {"bytes_written":1275444,"cfile_init":1,"dirs.queue_time_us":65,"dirs.run_cpu_time_us":263,"dirs.run_wall_time_us":1840,"drs_written":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1636,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:28.647717 30708 maintenance_manager.cc:419] P 1403e589655d45728c3f720f304b886e: Scheduling LogGCOp(5fcfbf0d13a64b0a9a25e15901324682): free 133024356 bytes of WAL
I20260812 06:19:28.648083 30639 log_reader.cc:385] T 5fcfbf0d13a64b0a9a25e15901324682: removed 13 log segments from log reader
I20260812 06:19:28.648178 30639 log.cc:1079] T 5fcfbf0d13a64b0a9a25e15901324682 P 1403e589655d45728c3f720f304b886e: Deleting log segment in path: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566566673-30521-0/minicluster-data/ts-0-root/wals/5fcfbf0d13a64b0a9a25e15901324682/wal-000000002 (ops 7-11)
I20260812 06:19:28.648267 30639 log.cc:1079] T 5fcfbf0d13a64b0a9a25e15901324682 P 1403e589655d45728c3f720f304b886e: Deleting log segment in path: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566566673-30521-0/minicluster-data/ts-0-root/wals/5fcfbf0d13a64b0a9a25e15901324682/wal-000000003 (ops 12-16)
I20260812 06:19:28.648341 30639 log.cc:1079] T 5fcfbf0d13a64b0a9a25e15901324682 P 1403e589655d45728c3f720f304b886e: Deleting log segment in path: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566566673-30521-0/minicluster-data/ts-0-root/wals/5fcfbf0d13a64b0a9a25e15901324682/wal-000000004 (ops 17-21)
I20260812 06:19:28.648388 30639 log.cc:1079] T 5fcfbf0d13a64b0a9a25e15901324682 P 1403e589655d45728c3f720f304b886e: Deleting log segment in path: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566566673-30521-0/minicluster-data/ts-0-root/wals/5fcfbf0d13a64b0a9a25e15901324682/wal-000000005 (ops 22-26)
I20260812 06:19:28.648432 30639 log.cc:1079] T 5fcfbf0d13a64b0a9a25e15901324682 P 1403e589655d45728c3f720f304b886e: Deleting log segment in path: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566566673-30521-0/minicluster-data/ts-0-root/wals/5fcfbf0d13a64b0a9a25e15901324682/wal-000000006 (ops 27-31)
I20260812 06:19:28.648471 30639 log.cc:1079] T 5fcfbf0d13a64b0a9a25e15901324682 P 1403e589655d45728c3f720f304b886e: Deleting log segment in path: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566566673-30521-0/minicluster-data/ts-0-root/wals/5fcfbf0d13a64b0a9a25e15901324682/wal-000000007 (ops 32-36)
I20260812 06:19:28.648520 30639 log.cc:1079] T 5fcfbf0d13a64b0a9a25e15901324682 P 1403e589655d45728c3f720f304b886e: Deleting log segment in path: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566566673-30521-0/minicluster-data/ts-0-root/wals/5fcfbf0d13a64b0a9a25e15901324682/wal-000000008 (ops 37-41)
I20260812 06:19:28.648563 30639 log.cc:1079] T 5fcfbf0d13a64b0a9a25e15901324682 P 1403e589655d45728c3f720f304b886e: Deleting log segment in path: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566566673-30521-0/minicluster-data/ts-0-root/wals/5fcfbf0d13a64b0a9a25e15901324682/wal-000000009 (ops 42-46)
I20260812 06:19:28.648603 30639 log.cc:1079] T 5fcfbf0d13a64b0a9a25e15901324682 P 1403e589655d45728c3f720f304b886e: Deleting log segment in path: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566566673-30521-0/minicluster-data/ts-0-root/wals/5fcfbf0d13a64b0a9a25e15901324682/wal-000000010 (ops 47-50)
I20260812 06:19:28.648644 30639 log.cc:1079] T 5fcfbf0d13a64b0a9a25e15901324682 P 1403e589655d45728c3f720f304b886e: Deleting log segment in path: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566566673-30521-0/minicluster-data/ts-0-root/wals/5fcfbf0d13a64b0a9a25e15901324682/wal-000000011 (ops 51-55)
I20260812 06:19:28.648689 30639 log.cc:1079] T 5fcfbf0d13a64b0a9a25e15901324682 P 1403e589655d45728c3f720f304b886e: Deleting log segment in path: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566566673-30521-0/minicluster-data/ts-0-root/wals/5fcfbf0d13a64b0a9a25e15901324682/wal-000000012 (ops 56-60)
I20260812 06:19:28.648731 30639 log.cc:1079] T 5fcfbf0d13a64b0a9a25e15901324682 P 1403e589655d45728c3f720f304b886e: Deleting log segment in path: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566566673-30521-0/minicluster-data/ts-0-root/wals/5fcfbf0d13a64b0a9a25e15901324682/wal-000000013 (ops 61-65)
I20260812 06:19:28.648774 30639 log.cc:1079] T 5fcfbf0d13a64b0a9a25e15901324682 P 1403e589655d45728c3f720f304b886e: Deleting log segment in path: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566566673-30521-0/minicluster-data/ts-0-root/wals/5fcfbf0d13a64b0a9a25e15901324682/wal-000000014 (ops 66-70)
I20260812 06:19:28.679422 30639 maintenance_manager.cc:643] P 1403e589655d45728c3f720f304b886e: LogGCOp(5fcfbf0d13a64b0a9a25e15901324682) complete. Timing: real 0.031s	user 0.000s	sys 0.031s Metrics: {}
I20260812 06:19:28.680030 30708 maintenance_manager.cc:419] P 1403e589655d45728c3f720f304b886e: Scheduling UndoDeltaBlockGCOp(5fcfbf0d13a64b0a9a25e15901324682): 482 bytes on disk
I20260812 06:19:28.680590 30639 maintenance_manager.cc:643] P 1403e589655d45728c3f720f304b886e: UndoDeltaBlockGCOp(5fcfbf0d13a64b0a9a25e15901324682) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":70,"lbm_reads_lt_1ms":4}
I20260812 06:19:28.681280 30708 maintenance_manager.cc:419] P 1403e589655d45728c3f720f304b886e: Scheduling FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682): perf score=3.181125
I20260812 06:19:28.694865 30639 maintenance_manager.cc:643] P 1403e589655d45728c3f720f304b886e: FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682) complete. Timing: real 0.013s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4635978,"delete_count":0,"lbm_write_time_us":4943,"lbm_writes_lt_1ms":116,"reinsert_count":0,"update_count":565}
I20260812 06:19:28.695401 30708 maintenance_manager.cc:419] P 1403e589655d45728c3f720f304b886e: Scheduling FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682): perf score=2.188937
I20260812 06:19:28.714370 30639 maintenance_manager.cc:643] P 1403e589655d45728c3f720f304b886e: FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682) complete. Timing: real 0.019s	user 0.005s	sys 0.010s Metrics: {"bytes_written":3569330,"delete_count":0,"lbm_write_time_us":3967,"lbm_writes_lt_1ms":90,"reinsert_count":0,"update_count":435}
I20260812 06:19:28.715080 30708 maintenance_manager.cc:419] P 1403e589655d45728c3f720f304b886e: Scheduling MajorDeltaCompactionOp(5fcfbf0d13a64b0a9a25e15901324682): perf score=1.000000
I20260812 06:19:28.946082 30639 maintenance_manager.cc:643] P 1403e589655d45728c3f720f304b886e: MajorDeltaCompactionOp(5fcfbf0d13a64b0a9a25e15901324682) complete. Timing: real 0.231s	user 0.153s	sys 0.077s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836364,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1249,"lbm_read_time_us":16930,"lbm_reads_lt_1ms":674,"lbm_write_time_us":39684,"lbm_writes_lt_1ms":643,"mutex_wait_us":550,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3200,"thread_start_us":78,"threads_started":1,"update_count":3000}
I20260812 06:19:28.946950 30708 maintenance_manager.cc:419] P 1403e589655d45728c3f720f304b886e: Scheduling FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682): perf score=14.095187
I20260812 06:19:29.010929 30639 maintenance_manager.cc:643] P 1403e589655d45728c3f720f304b886e: FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682) complete. Timing: real 0.064s	user 0.042s	sys 0.021s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":24223,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:29.011560 30708 maintenance_manager.cc:419] P 1403e589655d45728c3f720f304b886e: Scheduling FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682): perf score=2.188937
I20260812 06:19:29.023132 30639 maintenance_manager.cc:643] P 1403e589655d45728c3f720f304b886e: FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682) complete. Timing: real 0.011s	user 0.004s	sys 0.006s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4362,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:29.023658 30708 maintenance_manager.cc:419] P 1403e589655d45728c3f720f304b886e: Scheduling MajorDeltaCompactionOp(5fcfbf0d13a64b0a9a25e15901324682): perf score=1.000000
I20260812 06:19:29.199604 30639 maintenance_manager.cc:643] P 1403e589655d45728c3f720f304b886e: MajorDeltaCompactionOp(5fcfbf0d13a64b0a9a25e15901324682) complete. Timing: real 0.176s	user 0.124s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733724,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":699,"lbm_read_time_us":12855,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30435,"lbm_writes_lt_1ms":543,"mutex_wait_us":286,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:29.200204 30708 maintenance_manager.cc:419] P 1403e589655d45728c3f720f304b886e: Scheduling FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682): perf score=11.118625
I20260812 06:19:29.231575 30639 maintenance_manager.cc:643] P 1403e589655d45728c3f720f304b886e: FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682) complete. Timing: real 0.031s	user 0.010s	sys 0.020s Metrics: {"bytes_written":12717738,"delete_count":0,"lbm_write_time_us":13685,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:29.232231 30708 maintenance_manager.cc:419] P 1403e589655d45728c3f720f304b886e: Scheduling FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682): perf score=2.188937
I20260812 06:19:29.244804 30639 maintenance_manager.cc:643] P 1403e589655d45728c3f720f304b886e: FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682) complete. Timing: real 0.012s	user 0.003s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4635,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:29.245327 30708 maintenance_manager.cc:419] P 1403e589655d45728c3f720f304b886e: Scheduling MajorDeltaCompactionOp(5fcfbf0d13a64b0a9a25e15901324682): perf score=1.000000
I20260812 06:19:29.368745 30639 maintenance_manager.cc:643] P 1403e589655d45728c3f720f304b886e: MajorDeltaCompactionOp(5fcfbf0d13a64b0a9a25e15901324682) complete. Timing: real 0.123s	user 0.111s	sys 0.012s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631306,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":235,"lbm_read_time_us":7923,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24643,"lbm_writes_lt_1ms":443,"mutex_wait_us":29,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:29.369686 30708 maintenance_manager.cc:419] P 1403e589655d45728c3f720f304b886e: Scheduling FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682): perf score=10.126437
I20260812 06:19:29.415860 30639 maintenance_manager.cc:643] P 1403e589655d45728c3f720f304b886e: FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682) complete. Timing: real 0.046s	user 0.031s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18861,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:29.416410 30708 maintenance_manager.cc:419] P 1403e589655d45728c3f720f304b886e: Scheduling FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682): perf score=2.188937
I20260812 06:19:29.427768 30639 maintenance_manager.cc:643] P 1403e589655d45728c3f720f304b886e: FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682) complete. Timing: real 0.011s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3988,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:29.428771 30708 maintenance_manager.cc:419] P 1403e589655d45728c3f720f304b886e: Scheduling MajorDeltaCompactionOp(5fcfbf0d13a64b0a9a25e15901324682): perf score=1.000000
I20260812 06:19:29.562945 30639 maintenance_manager.cc:643] P 1403e589655d45728c3f720f304b886e: MajorDeltaCompactionOp(5fcfbf0d13a64b0a9a25e15901324682) complete. Timing: real 0.134s	user 0.092s	sys 0.041s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":556,"lbm_read_time_us":7805,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24510,"lbm_writes_lt_1ms":443,"mutex_wait_us":74,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4864,"update_count":2000}
I20260812 06:19:29.563540 30708 maintenance_manager.cc:419] P 1403e589655d45728c3f720f304b886e: Scheduling FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682): perf score=10.126437
I20260812 06:19:29.608420 30639 maintenance_manager.cc:643] P 1403e589655d45728c3f720f304b886e: FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682) complete. Timing: real 0.045s	user 0.027s	sys 0.013s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":20106,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:19:29.609005 30708 maintenance_manager.cc:419] P 1403e589655d45728c3f720f304b886e: Scheduling FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682): perf score=2.188937
I20260812 06:19:29.621127 30639 maintenance_manager.cc:643] P 1403e589655d45728c3f720f304b886e: FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682) complete. Timing: real 0.012s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3980,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:29.621702 30708 maintenance_manager.cc:419] P 1403e589655d45728c3f720f304b886e: Scheduling MajorDeltaCompactionOp(5fcfbf0d13a64b0a9a25e15901324682): perf score=1.000000
I20260812 06:19:29.762624 30639 maintenance_manager.cc:643] P 1403e589655d45728c3f720f304b886e: MajorDeltaCompactionOp(5fcfbf0d13a64b0a9a25e15901324682) complete. Timing: real 0.141s	user 0.100s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1285,"lbm_read_time_us":11428,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24903,"lbm_writes_lt_1ms":443,"mutex_wait_us":315,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2000}
I20260812 06:19:29.763479 30708 maintenance_manager.cc:419] P 1403e589655d45728c3f720f304b886e: Scheduling FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682): perf score=10.126437
I20260812 06:19:29.814568 30639 maintenance_manager.cc:643] P 1403e589655d45728c3f720f304b886e: FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682) complete. Timing: real 0.051s	user 0.026s	sys 0.023s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17764,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":1500}
I20260812 06:19:29.815248 30708 maintenance_manager.cc:419] P 1403e589655d45728c3f720f304b886e: Scheduling FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682): perf score=2.188937
I20260812 06:19:29.827157 30639 maintenance_manager.cc:643] P 1403e589655d45728c3f720f304b886e: FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682) complete. Timing: real 0.012s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4697,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:29.827709 30708 maintenance_manager.cc:419] P 1403e589655d45728c3f720f304b886e: Scheduling MajorDeltaCompactionOp(5fcfbf0d13a64b0a9a25e15901324682): perf score=1.000000
I20260812 06:19:29.984416 30639 maintenance_manager.cc:643] P 1403e589655d45728c3f720f304b886e: MajorDeltaCompactionOp(5fcfbf0d13a64b0a9a25e15901324682) complete. Timing: real 0.157s	user 0.100s	sys 0.056s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631313,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":498,"lbm_read_time_us":11698,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23820,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8960,"update_count":2000}
I20260812 06:19:29.985200 30708 maintenance_manager.cc:419] P 1403e589655d45728c3f720f304b886e: Scheduling FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682): perf score=10.126437
I20260812 06:19:30.024111 30639 maintenance_manager.cc:643] P 1403e589655d45728c3f720f304b886e: FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682) complete. Timing: real 0.039s	user 0.009s	sys 0.027s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16360,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:30.024639 30708 maintenance_manager.cc:419] P 1403e589655d45728c3f720f304b886e: Scheduling FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682): perf score=2.188937
I20260812 06:19:30.036350 30639 maintenance_manager.cc:643] P 1403e589655d45728c3f720f304b886e: FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4195,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:30.036881 30708 maintenance_manager.cc:419] P 1403e589655d45728c3f720f304b886e: Scheduling MajorDeltaCompactionOp(5fcfbf0d13a64b0a9a25e15901324682): perf score=1.000000
I20260812 06:19:30.177992 30639 maintenance_manager.cc:643] P 1403e589655d45728c3f720f304b886e: MajorDeltaCompactionOp(5fcfbf0d13a64b0a9a25e15901324682) complete. Timing: real 0.141s	user 0.099s	sys 0.042s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631311,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":256,"lbm_read_time_us":9774,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28000,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:19:30.178617 30708 maintenance_manager.cc:419] P 1403e589655d45728c3f720f304b886e: Scheduling FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682): perf score=10.126437
I20260812 06:19:30.222303 30639 maintenance_manager.cc:643] P 1403e589655d45728c3f720f304b886e: FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682) complete. Timing: real 0.043s	user 0.019s	sys 0.017s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16985,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:30.222960 30708 maintenance_manager.cc:419] P 1403e589655d45728c3f720f304b886e: Scheduling FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682): perf score=2.188937
I20260812 06:19:30.234217 30639 maintenance_manager.cc:643] P 1403e589655d45728c3f720f304b886e: FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682) complete. Timing: real 0.011s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4361,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:30.234918 30708 maintenance_manager.cc:419] P 1403e589655d45728c3f720f304b886e: Scheduling FlushMRSOp(5fcfbf0d13a64b0a9a25e15901324682): perf score=1.000000
I20260812 06:19:30.268071 30639 maintenance_manager.cc:643] P 1403e589655d45728c3f720f304b886e: FlushMRSOp(5fcfbf0d13a64b0a9a25e15901324682) complete. Timing: real 0.033s	user 0.031s	sys 0.000s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":90,"dirs.run_cpu_time_us":176,"dirs.run_wall_time_us":1845,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1705,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:30.268846 30708 maintenance_manager.cc:419] P 1403e589655d45728c3f720f304b886e: Scheduling LogGCOp(5fcfbf0d13a64b0a9a25e15901324682): free 124257253 bytes of WAL
I20260812 06:19:30.269099 30639 log_reader.cc:385] T 5fcfbf0d13a64b0a9a25e15901324682: removed 12 log segments from log reader
I20260812 06:19:30.269145 30639 log.cc:1079] T 5fcfbf0d13a64b0a9a25e15901324682 P 1403e589655d45728c3f720f304b886e: Deleting log segment in path: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566566673-30521-0/minicluster-data/ts-0-root/wals/5fcfbf0d13a64b0a9a25e15901324682/wal-000000015 (ops 71-75)
I20260812 06:19:30.269173 30639 log.cc:1079] T 5fcfbf0d13a64b0a9a25e15901324682 P 1403e589655d45728c3f720f304b886e: Deleting log segment in path: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566566673-30521-0/minicluster-data/ts-0-root/wals/5fcfbf0d13a64b0a9a25e15901324682/wal-000000016 (ops 76-80)
I20260812 06:19:30.269238 30639 log.cc:1079] T 5fcfbf0d13a64b0a9a25e15901324682 P 1403e589655d45728c3f720f304b886e: Deleting log segment in path: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566566673-30521-0/minicluster-data/ts-0-root/wals/5fcfbf0d13a64b0a9a25e15901324682/wal-000000017 (ops 81-84)
I20260812 06:19:30.269285 30639 log.cc:1079] T 5fcfbf0d13a64b0a9a25e15901324682 P 1403e589655d45728c3f720f304b886e: Deleting log segment in path: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566566673-30521-0/minicluster-data/ts-0-root/wals/5fcfbf0d13a64b0a9a25e15901324682/wal-000000018 (ops 85-89)
I20260812 06:19:30.269323 30639 log.cc:1079] T 5fcfbf0d13a64b0a9a25e15901324682 P 1403e589655d45728c3f720f304b886e: Deleting log segment in path: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566566673-30521-0/minicluster-data/ts-0-root/wals/5fcfbf0d13a64b0a9a25e15901324682/wal-000000019 (ops 90-94)
I20260812 06:19:30.269387 30639 log.cc:1079] T 5fcfbf0d13a64b0a9a25e15901324682 P 1403e589655d45728c3f720f304b886e: Deleting log segment in path: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566566673-30521-0/minicluster-data/ts-0-root/wals/5fcfbf0d13a64b0a9a25e15901324682/wal-000000020 (ops 95-99)
I20260812 06:19:30.269429 30639 log.cc:1079] T 5fcfbf0d13a64b0a9a25e15901324682 P 1403e589655d45728c3f720f304b886e: Deleting log segment in path: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566566673-30521-0/minicluster-data/ts-0-root/wals/5fcfbf0d13a64b0a9a25e15901324682/wal-000000021 (ops 100-104)
I20260812 06:19:30.269469 30639 log.cc:1079] T 5fcfbf0d13a64b0a9a25e15901324682 P 1403e589655d45728c3f720f304b886e: Deleting log segment in path: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566566673-30521-0/minicluster-data/ts-0-root/wals/5fcfbf0d13a64b0a9a25e15901324682/wal-000000022 (ops 105-109)
I20260812 06:19:30.269516 30639 log.cc:1079] T 5fcfbf0d13a64b0a9a25e15901324682 P 1403e589655d45728c3f720f304b886e: Deleting log segment in path: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566566673-30521-0/minicluster-data/ts-0-root/wals/5fcfbf0d13a64b0a9a25e15901324682/wal-000000023 (ops 110-114)
I20260812 06:19:30.269555 30639 log.cc:1079] T 5fcfbf0d13a64b0a9a25e15901324682 P 1403e589655d45728c3f720f304b886e: Deleting log segment in path: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566566673-30521-0/minicluster-data/ts-0-root/wals/5fcfbf0d13a64b0a9a25e15901324682/wal-000000024 (ops 115-119)
I20260812 06:19:30.269594 30639 log.cc:1079] T 5fcfbf0d13a64b0a9a25e15901324682 P 1403e589655d45728c3f720f304b886e: Deleting log segment in path: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566566673-30521-0/minicluster-data/ts-0-root/wals/5fcfbf0d13a64b0a9a25e15901324682/wal-000000025 (ops 120-124)
I20260812 06:19:30.269623 30639 log.cc:1079] T 5fcfbf0d13a64b0a9a25e15901324682 P 1403e589655d45728c3f720f304b886e: Deleting log segment in path: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566566673-30521-0/minicluster-data/ts-0-root/wals/5fcfbf0d13a64b0a9a25e15901324682/wal-000000026 (ops 125-129)
I20260812 06:19:30.299042 30639 maintenance_manager.cc:643] P 1403e589655d45728c3f720f304b886e: LogGCOp(5fcfbf0d13a64b0a9a25e15901324682) complete. Timing: real 0.030s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:19:30.299628 30708 maintenance_manager.cc:419] P 1403e589655d45728c3f720f304b886e: Scheduling UndoDeltaBlockGCOp(5fcfbf0d13a64b0a9a25e15901324682): 482 bytes on disk
I20260812 06:19:30.300431 30639 maintenance_manager.cc:643] P 1403e589655d45728c3f720f304b886e: UndoDeltaBlockGCOp(5fcfbf0d13a64b0a9a25e15901324682) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":83,"lbm_reads_lt_1ms":4}
I20260812 06:19:30.301188 30708 maintenance_manager.cc:419] P 1403e589655d45728c3f720f304b886e: Scheduling FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682): perf score=3.181125
I20260812 06:19:30.316494 30639 maintenance_manager.cc:643] P 1403e589655d45728c3f720f304b886e: FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682) complete. Timing: real 0.015s	user 0.008s	sys 0.005s Metrics: {"bytes_written":4964170,"delete_count":0,"lbm_write_time_us":5938,"lbm_writes_lt_1ms":124,"reinsert_count":0,"update_count":605}
I20260812 06:19:30.317109 30708 maintenance_manager.cc:419] P 1403e589655d45728c3f720f304b886e: Scheduling LogGCOp(5fcfbf0d13a64b0a9a25e15901324682): free 12017954 bytes of WAL
I20260812 06:19:30.317368 30639 log_reader.cc:385] T 5fcfbf0d13a64b0a9a25e15901324682: removed 1 log segments from log reader
I20260812 06:19:30.317448 30639 log.cc:1079] T 5fcfbf0d13a64b0a9a25e15901324682 P 1403e589655d45728c3f720f304b886e: Deleting log segment in path: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566566673-30521-0/minicluster-data/ts-0-root/wals/5fcfbf0d13a64b0a9a25e15901324682/wal-000000027 (ops 130-134)
I20260812 06:19:30.319979 30639 maintenance_manager.cc:643] P 1403e589655d45728c3f720f304b886e: LogGCOp(5fcfbf0d13a64b0a9a25e15901324682) complete. Timing: real 0.003s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:19:30.320340 30708 maintenance_manager.cc:419] P 1403e589655d45728c3f720f304b886e: Scheduling FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682): perf score=2.188937
I20260812 06:19:30.333477 30639 maintenance_manager.cc:643] P 1403e589655d45728c3f720f304b886e: FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682) complete. Timing: real 0.013s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3241130,"delete_count":0,"lbm_write_time_us":4253,"lbm_writes_lt_1ms":82,"reinsert_count":0,"update_count":395}
I20260812 06:19:30.333985 30708 maintenance_manager.cc:419] P 1403e589655d45728c3f720f304b886e: Scheduling MajorDeltaCompactionOp(5fcfbf0d13a64b0a9a25e15901324682): perf score=1.000000
I20260812 06:19:30.520696 30639 maintenance_manager.cc:643] P 1403e589655d45728c3f720f304b886e: MajorDeltaCompactionOp(5fcfbf0d13a64b0a9a25e15901324682) complete. Timing: real 0.187s	user 0.164s	sys 0.020s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836355,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":397,"lbm_read_time_us":11313,"lbm_reads_lt_1ms":666,"lbm_write_time_us":38177,"lbm_writes_lt_1ms":643,"mutex_wait_us":73,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1664,"thread_start_us":84,"threads_started":1,"update_count":3000}
I20260812 06:19:30.521529 30708 maintenance_manager.cc:419] P 1403e589655d45728c3f720f304b886e: Scheduling FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682): perf score=14.095187
I20260812 06:19:30.575050 30639 maintenance_manager.cc:643] P 1403e589655d45728c3f720f304b886e: FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682) complete. Timing: real 0.053s	user 0.021s	sys 0.031s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23977,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:30.575619 30708 maintenance_manager.cc:419] P 1403e589655d45728c3f720f304b886e: Scheduling FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682): perf score=2.188937
I20260812 06:19:30.588271 30639 maintenance_manager.cc:643] P 1403e589655d45728c3f720f304b886e: FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682) complete. Timing: real 0.012s	user 0.010s	sys 0.000s 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:19:30.588764 30708 maintenance_manager.cc:419] P 1403e589655d45728c3f720f304b886e: Scheduling MajorDeltaCompactionOp(5fcfbf0d13a64b0a9a25e15901324682): perf score=1.000000
I20260812 06:19:30.742869 30639 maintenance_manager.cc:643] P 1403e589655d45728c3f720f304b886e: MajorDeltaCompactionOp(5fcfbf0d13a64b0a9a25e15901324682) complete. Timing: real 0.154s	user 0.101s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733724,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":858,"lbm_read_time_us":9959,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30619,"lbm_writes_lt_1ms":543,"mutex_wait_us":110,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":18944,"update_count":2500}
I20260812 06:19:30.746393 30708 maintenance_manager.cc:419] P 1403e589655d45728c3f720f304b886e: Scheduling FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682): perf score=13.103000
I20260812 06:19:30.789318 30639 maintenance_manager.cc:643] P 1403e589655d45728c3f720f304b886e: FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682) complete. Timing: real 0.043s	user 0.027s	sys 0.013s Metrics: {"bytes_written":14768931,"delete_count":0,"lbm_write_time_us":18609,"lbm_writes_lt_1ms":363,"reinsert_count":0,"update_count":1800}
I20260812 06:19:30.789875 30708 maintenance_manager.cc:419] P 1403e589655d45728c3f720f304b886e: Scheduling FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682): perf score=1.000000
I20260812 06:19:30.796941 30639 maintenance_manager.cc:643] P 1403e589655d45728c3f720f304b886e: FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682) complete. Timing: real 0.007s	user 0.005s	sys 0.000s Metrics: {"bytes_written":2051406,"delete_count":0,"lbm_write_time_us":2370,"lbm_writes_lt_1ms":53,"reinsert_count":0,"update_count":250}
I20260812 06:19:30.797462 30708 maintenance_manager.cc:419] P 1403e589655d45728c3f720f304b886e: Scheduling MajorDeltaCompactionOp(5fcfbf0d13a64b0a9a25e15901324682): perf score=1.000000
I20260812 06:19:30.954706 30639 maintenance_manager.cc:643] P 1403e589655d45728c3f720f304b886e: MajorDeltaCompactionOp(5fcfbf0d13a64b0a9a25e15901324682) complete. Timing: real 0.157s	user 0.124s	sys 0.032s Metrics: {"cfile_cache_miss":442,"cfile_cache_miss_bytes":21041501,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":322,"lbm_read_time_us":10307,"lbm_reads_lt_1ms":474,"lbm_write_time_us":28894,"lbm_writes_lt_1ms":453,"mutex_wait_us":90,"peak_mem_usage":51099678,"reinsert_count":0,"spinlock_wait_cycles":4992,"update_count":2050}
I20260812 06:19:30.955546 30708 maintenance_manager.cc:419] P 1403e589655d45728c3f720f304b886e: Scheduling FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682): perf score=10.126437
I20260812 06:19:30.989205 30639 maintenance_manager.cc:643] P 1403e589655d45728c3f720f304b886e: FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682) complete. Timing: real 0.033s	user 0.017s	sys 0.014s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":14309,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:30.989853 30708 maintenance_manager.cc:419] P 1403e589655d45728c3f720f304b886e: Scheduling FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682): perf score=2.188937
I20260812 06:19:31.007182 30639 maintenance_manager.cc:643] P 1403e589655d45728c3f720f304b886e: FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682) complete. Timing: real 0.017s	user 0.013s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6452,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:31.007820 30708 maintenance_manager.cc:419] P 1403e589655d45728c3f720f304b886e: Scheduling MajorDeltaCompactionOp(5fcfbf0d13a64b0a9a25e15901324682): perf score=1.000000
I20260812 06:19:31.135401 30639 maintenance_manager.cc:643] P 1403e589655d45728c3f720f304b886e: MajorDeltaCompactionOp(5fcfbf0d13a64b0a9a25e15901324682) complete. Timing: real 0.127s	user 0.111s	sys 0.016s Metrics: {"cfile_cache_miss":422,"cfile_cache_miss_bytes":20221059,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":565,"lbm_read_time_us":7918,"lbm_reads_lt_1ms":462,"lbm_write_time_us":25363,"lbm_writes_lt_1ms":433,"mutex_wait_us":32,"peak_mem_usage":49238594,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":1950}
I20260812 06:19:31.136111 30708 maintenance_manager.cc:419] P 1403e589655d45728c3f720f304b886e: Scheduling FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682): perf score=10.126437
I20260812 06:19:31.180413 30639 maintenance_manager.cc:643] P 1403e589655d45728c3f720f304b886e: FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682) complete. Timing: real 0.044s	user 0.021s	sys 0.012s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":14544,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:31.181110 30708 maintenance_manager.cc:419] P 1403e589655d45728c3f720f304b886e: Scheduling FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682): perf score=2.188937
I20260812 06:19:31.194165 30639 maintenance_manager.cc:643] P 1403e589655d45728c3f720f304b886e: FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682) complete. Timing: real 0.013s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4480,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:31.194938 30708 maintenance_manager.cc:419] P 1403e589655d45728c3f720f304b886e: Scheduling MajorDeltaCompactionOp(5fcfbf0d13a64b0a9a25e15901324682): perf score=1.000000
I20260812 06:19:31.321511 30639 maintenance_manager.cc:643] P 1403e589655d45728c3f720f304b886e: MajorDeltaCompactionOp(5fcfbf0d13a64b0a9a25e15901324682) complete. Timing: real 0.126s	user 0.110s	sys 0.016s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631313,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":2117,"lbm_read_time_us":8098,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23360,"lbm_writes_lt_1ms":443,"mutex_wait_us":556,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6656,"update_count":2000}
I20260812 06:19:31.322173 30708 maintenance_manager.cc:419] P 1403e589655d45728c3f720f304b886e: Scheduling FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682): perf score=10.126437
I20260812 06:19:31.372640 30639 maintenance_manager.cc:643] P 1403e589655d45728c3f720f304b886e: FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682) complete. Timing: real 0.050s	user 0.025s	sys 0.014s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":18022,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:31.373344 30708 maintenance_manager.cc:419] P 1403e589655d45728c3f720f304b886e: Scheduling FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682): perf score=2.188937
I20260812 06:19:31.385673 30639 maintenance_manager.cc:643] P 1403e589655d45728c3f720f304b886e: FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682) complete. Timing: real 0.012s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4365,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:31.386199 30708 maintenance_manager.cc:419] P 1403e589655d45728c3f720f304b886e: Scheduling MajorDeltaCompactionOp(5fcfbf0d13a64b0a9a25e15901324682): perf score=1.000000
I20260812 06:19:31.524320 30639 maintenance_manager.cc:643] P 1403e589655d45728c3f720f304b886e: MajorDeltaCompactionOp(5fcfbf0d13a64b0a9a25e15901324682) complete. Timing: real 0.138s	user 0.121s	sys 0.015s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":383,"lbm_read_time_us":9360,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28213,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":442,"mutex_wait_us":68,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9472,"update_count":2000}
I20260812 06:19:31.525130 30708 maintenance_manager.cc:419] P 1403e589655d45728c3f720f304b886e: Scheduling FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682): perf score=10.126437
I20260812 06:19:31.577665 30639 maintenance_manager.cc:643] P 1403e589655d45728c3f720f304b886e: FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682) complete. Timing: real 0.052s	user 0.006s	sys 0.036s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":16186,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:31.578521 30708 maintenance_manager.cc:419] P 1403e589655d45728c3f720f304b886e: Scheduling FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682): perf score=2.188937
I20260812 06:19:31.589936 30639 maintenance_manager.cc:643] P 1403e589655d45728c3f720f304b886e: FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4369,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:31.590444 30708 maintenance_manager.cc:419] P 1403e589655d45728c3f720f304b886e: Scheduling MajorDeltaCompactionOp(5fcfbf0d13a64b0a9a25e15901324682): perf score=1.000000
I20260812 06:19:31.754649 30639 maintenance_manager.cc:643] P 1403e589655d45728c3f720f304b886e: MajorDeltaCompactionOp(5fcfbf0d13a64b0a9a25e15901324682) complete. Timing: real 0.164s	user 0.109s	sys 0.049s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631314,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":454,"lbm_read_time_us":10929,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26187,"lbm_writes_lt_1ms":443,"mutex_wait_us":107,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:31.755503 30708 maintenance_manager.cc:419] P 1403e589655d45728c3f720f304b886e: Scheduling FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682): perf score=10.126437
I20260812 06:19:31.801708 30639 maintenance_manager.cc:643] P 1403e589655d45728c3f720f304b886e: FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682) complete. Timing: real 0.046s	user 0.025s	sys 0.008s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":15483,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:31.802248 30708 maintenance_manager.cc:419] P 1403e589655d45728c3f720f304b886e: Scheduling FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682): perf score=2.188937
I20260812 06:19:31.815428 30639 maintenance_manager.cc:643] P 1403e589655d45728c3f720f304b886e: FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682) complete. Timing: real 0.013s	user 0.006s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4668,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:31.815996 30708 maintenance_manager.cc:419] P 1403e589655d45728c3f720f304b886e: Scheduling FlushMRSOp(5fcfbf0d13a64b0a9a25e15901324682): perf score=1.000000
I20260812 06:19:31.856099 30639 maintenance_manager.cc:643] P 1403e589655d45728c3f720f304b886e: FlushMRSOp(5fcfbf0d13a64b0a9a25e15901324682) complete. Timing: real 0.040s	user 0.037s	sys 0.001s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":104,"dirs.run_cpu_time_us":216,"dirs.run_wall_time_us":1528,"drs_written":1,"lbm_read_time_us":69,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2298,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:31.856902 30708 maintenance_manager.cc:419] P 1403e589655d45728c3f720f304b886e: Scheduling LogGCOp(5fcfbf0d13a64b0a9a25e15901324682): free 120553652 bytes of WAL
I20260812 06:19:31.857261 30639 log_reader.cc:385] T 5fcfbf0d13a64b0a9a25e15901324682: removed 12 log segments from log reader
I20260812 06:19:31.857380 30639 log.cc:1079] T 5fcfbf0d13a64b0a9a25e15901324682 P 1403e589655d45728c3f720f304b886e: Deleting log segment in path: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566566673-30521-0/minicluster-data/ts-0-root/wals/5fcfbf0d13a64b0a9a25e15901324682/wal-000000028 (ops 135-139)
I20260812 06:19:31.857442 30639 log.cc:1079] T 5fcfbf0d13a64b0a9a25e15901324682 P 1403e589655d45728c3f720f304b886e: Deleting log segment in path: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566566673-30521-0/minicluster-data/ts-0-root/wals/5fcfbf0d13a64b0a9a25e15901324682/wal-000000029 (ops 140-144)
I20260812 06:19:31.857491 30639 log.cc:1079] T 5fcfbf0d13a64b0a9a25e15901324682 P 1403e589655d45728c3f720f304b886e: Deleting log segment in path: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566566673-30521-0/minicluster-data/ts-0-root/wals/5fcfbf0d13a64b0a9a25e15901324682/wal-000000030 (ops 145-148)
I20260812 06:19:31.857528 30639 log.cc:1079] T 5fcfbf0d13a64b0a9a25e15901324682 P 1403e589655d45728c3f720f304b886e: Deleting log segment in path: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566566673-30521-0/minicluster-data/ts-0-root/wals/5fcfbf0d13a64b0a9a25e15901324682/wal-000000031 (ops 149-153)
I20260812 06:19:31.857569 30639 log.cc:1079] T 5fcfbf0d13a64b0a9a25e15901324682 P 1403e589655d45728c3f720f304b886e: Deleting log segment in path: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566566673-30521-0/minicluster-data/ts-0-root/wals/5fcfbf0d13a64b0a9a25e15901324682/wal-000000032 (ops 154-158)
I20260812 06:19:31.857600 30639 log.cc:1079] T 5fcfbf0d13a64b0a9a25e15901324682 P 1403e589655d45728c3f720f304b886e: Deleting log segment in path: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566566673-30521-0/minicluster-data/ts-0-root/wals/5fcfbf0d13a64b0a9a25e15901324682/wal-000000033 (ops 159-163)
I20260812 06:19:31.857640 30639 log.cc:1079] T 5fcfbf0d13a64b0a9a25e15901324682 P 1403e589655d45728c3f720f304b886e: Deleting log segment in path: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566566673-30521-0/minicluster-data/ts-0-root/wals/5fcfbf0d13a64b0a9a25e15901324682/wal-000000034 (ops 164-168)
I20260812 06:19:31.857672 30639 log.cc:1079] T 5fcfbf0d13a64b0a9a25e15901324682 P 1403e589655d45728c3f720f304b886e: Deleting log segment in path: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566566673-30521-0/minicluster-data/ts-0-root/wals/5fcfbf0d13a64b0a9a25e15901324682/wal-000000035 (ops 169-172)
I20260812 06:19:31.857736 30639 log.cc:1079] T 5fcfbf0d13a64b0a9a25e15901324682 P 1403e589655d45728c3f720f304b886e: Deleting log segment in path: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566566673-30521-0/minicluster-data/ts-0-root/wals/5fcfbf0d13a64b0a9a25e15901324682/wal-000000036 (ops 173-177)
I20260812 06:19:31.857784 30639 log.cc:1079] T 5fcfbf0d13a64b0a9a25e15901324682 P 1403e589655d45728c3f720f304b886e: Deleting log segment in path: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566566673-30521-0/minicluster-data/ts-0-root/wals/5fcfbf0d13a64b0a9a25e15901324682/wal-000000037 (ops 178-182)
I20260812 06:19:31.857816 30639 log.cc:1079] T 5fcfbf0d13a64b0a9a25e15901324682 P 1403e589655d45728c3f720f304b886e: Deleting log segment in path: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566566673-30521-0/minicluster-data/ts-0-root/wals/5fcfbf0d13a64b0a9a25e15901324682/wal-000000038 (ops 183-187)
I20260812 06:19:31.857851 30639 log.cc:1079] T 5fcfbf0d13a64b0a9a25e15901324682 P 1403e589655d45728c3f720f304b886e: Deleting log segment in path: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515566566673-30521-0/minicluster-data/ts-0-root/wals/5fcfbf0d13a64b0a9a25e15901324682/wal-000000039 (ops 188-192)
I20260812 06:19:31.887717 30639 maintenance_manager.cc:643] P 1403e589655d45728c3f720f304b886e: LogGCOp(5fcfbf0d13a64b0a9a25e15901324682) complete. Timing: real 0.031s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:19:31.888223 30708 maintenance_manager.cc:419] P 1403e589655d45728c3f720f304b886e: Scheduling UndoDeltaBlockGCOp(5fcfbf0d13a64b0a9a25e15901324682): 482 bytes on disk
I20260812 06:19:31.888819 30639 maintenance_manager.cc:643] P 1403e589655d45728c3f720f304b886e: UndoDeltaBlockGCOp(5fcfbf0d13a64b0a9a25e15901324682) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4}
I20260812 06:19:31.889582 30708 maintenance_manager.cc:419] P 1403e589655d45728c3f720f304b886e: Scheduling FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682): perf score=5.165500
I20260812 06:19:31.917881 30639 maintenance_manager.cc:643] P 1403e589655d45728c3f720f304b886e: FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682) complete. Timing: real 0.028s	user 0.012s	sys 0.012s Metrics: {"bytes_written":7220497,"delete_count":0,"lbm_write_time_us":8101,"lbm_writes_lt_1ms":179,"reinsert_count":0,"update_count":880}
I20260812 06:19:31.918555 30708 maintenance_manager.cc:419] P 1403e589655d45728c3f720f304b886e: Scheduling MajorDeltaCompactionOp(5fcfbf0d13a64b0a9a25e15901324682): perf score=1.000000
I20260812 06:19:32.009291 30521 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.093s	user 1.854s	sys 0.125s
I20260812 06:19:32.101814 30521 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.092s	user 0.002s	sys 0.000s
I20260812 06:19:32.102619 30521 tablet_server.cc:179] TabletServer@127.29.206.65:0 shutting down...
I20260812 06:19:32.105816 30639 maintenance_manager.cc:643] P 1403e589655d45728c3f720f304b886e: MajorDeltaCompactionOp(5fcfbf0d13a64b0a9a25e15901324682) complete. Timing: real 0.187s	user 0.125s	sys 0.061s Metrics: {"cfile_cache_miss":609,"cfile_cache_miss_bytes":27851678,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":531,"lbm_read_time_us":13303,"lbm_reads_lt_1ms":637,"lbm_write_time_us":31355,"lbm_writes_lt_1ms":619,"mutex_wait_us":22,"peak_mem_usage":72476864,"reinsert_count":0,"spinlock_wait_cycles":18560,"thread_start_us":86,"threads_started":1,"update_count":2880}
I20260812 06:19:32.107366 30708 maintenance_manager.cc:419] P 1403e589655d45728c3f720f304b886e: Scheduling FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682): perf score=7.149875
I20260812 06:19:32.133635 30639 maintenance_manager.cc:643] P 1403e589655d45728c3f720f304b886e: FlushDeltaMemStoresOp(5fcfbf0d13a64b0a9a25e15901324682) complete. Timing: real 0.026s	user 0.016s	sys 0.008s Metrics: {"bytes_written":9189660,"delete_count":0,"lbm_write_time_us":10377,"lbm_writes_lt_1ms":227,"reinsert_count":0,"update_count":1120}
I20260812 06:19:32.134387 30521 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:32.134853 30521 tablet_replica.cc:333] T 5fcfbf0d13a64b0a9a25e15901324682 P 1403e589655d45728c3f720f304b886e: stopping tablet replica
I20260812 06:19:32.135098 30521 raft_consensus.cc:2243] T 5fcfbf0d13a64b0a9a25e15901324682 P 1403e589655d45728c3f720f304b886e [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:32.135342 30521 raft_consensus.cc:2272] T 5fcfbf0d13a64b0a9a25e15901324682 P 1403e589655d45728c3f720f304b886e [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:32.151026 30521 tablet_server.cc:196] TabletServer@127.29.206.65:0 shutdown complete.
I20260812 06:19:32.156090 30521 master.cc:562] Master@127.29.206.126:33005 shutting down...
I20260812 06:19:32.160681 30521 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 0ef3b57aef9c403780cb8d9be88ca044 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:32.160889 30521 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 0ef3b57aef9c403780cb8d9be88ca044 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:32.161234 30521 tablet_replica.cc:333] T 00000000000000000000000000000000 P 0ef3b57aef9c403780cb8d9be88ca044: stopping tablet replica
I20260812 06:19:32.173802 30521 master.cc:584] Master@127.29.206.126:33005 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5686 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:19:32.278056 30521 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.29.206.126:36223
I20260812 06:19:32.278602 30521 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:32.281338 30747 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:19:32.281397 30521 server_base.cc:1061] running on GCE node
W20260812 06:19:32.281435 30748 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:19:32.281616 30750 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:32.281850 30521 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:32.281896 30521 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:19:32.281931 30521 hybrid_clock.cc:648] HybridClock initialized: now 1786515572281930 us; error 0 us; skew 500 ppm
I20260812 06:19:32.282848 30521 webserver.cc:533] Webserver started at http://127.29.206.126:38783/ using document root <none> and password file <none>
I20260812 06:19:32.283054 30521 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:32.283150 30521 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:32.283269 30521 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:32.283690 30521 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566566673-30521-0/minicluster-data/master-0-root/instance:
uuid: "a822dcc8dab14e098dc5826830e416ff"
format_stamp: "Formatted at 2026-08-12 06:19:32 on dist-test-slave-5l3k"
I20260812 06:19:32.285163 30521 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:19:32.286089 30755 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:19:32.286334 30521 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:19:32.286434 30521 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566566673-30521-0/minicluster-data/master-0-root
uuid: "a822dcc8dab14e098dc5826830e416ff"
format_stamp: "Formatted at 2026-08-12 06:19:32 on dist-test-slave-5l3k"
I20260812 06:19:32.286556 30521 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566566673-30521-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566566673-30521-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566566673-30521-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:19:32.299947 30521 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:32.300383 30521 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:32.305086 30521 rpc_server.cc:307] RPC server started. Bound to: 127.29.206.126:36223
I20260812 06:19:32.308816 30816 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.29.206.126:36223 every 8 connection(s)
I20260812 06:19:32.309356 30817 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:19:32.311272 30817 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P a822dcc8dab14e098dc5826830e416ff: Bootstrap starting.
I20260812 06:19:32.312068 30817 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P a822dcc8dab14e098dc5826830e416ff: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:32.313253 30817 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P a822dcc8dab14e098dc5826830e416ff: No bootstrap required, opened a new log
I20260812 06:19:32.313679 30817 raft_consensus.cc:359] T 00000000000000000000000000000000 P a822dcc8dab14e098dc5826830e416ff [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a822dcc8dab14e098dc5826830e416ff" member_type: VOTER }
I20260812 06:19:32.313792 30817 raft_consensus.cc:385] T 00000000000000000000000000000000 P a822dcc8dab14e098dc5826830e416ff [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:32.313845 30817 raft_consensus.cc:740] T 00000000000000000000000000000000 P a822dcc8dab14e098dc5826830e416ff [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: a822dcc8dab14e098dc5826830e416ff, State: Initialized, Role: FOLLOWER
I20260812 06:19:32.314016 30817 consensus_queue.cc:260] T 00000000000000000000000000000000 P a822dcc8dab14e098dc5826830e416ff [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: "a822dcc8dab14e098dc5826830e416ff" member_type: VOTER }
I20260812 06:19:32.314121 30817 raft_consensus.cc:399] T 00000000000000000000000000000000 P a822dcc8dab14e098dc5826830e416ff [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:32.314167 30817 raft_consensus.cc:493] T 00000000000000000000000000000000 P a822dcc8dab14e098dc5826830e416ff [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:32.314221 30817 raft_consensus.cc:3060] T 00000000000000000000000000000000 P a822dcc8dab14e098dc5826830e416ff [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:32.314965 30817 raft_consensus.cc:515] T 00000000000000000000000000000000 P a822dcc8dab14e098dc5826830e416ff [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a822dcc8dab14e098dc5826830e416ff" member_type: VOTER }
I20260812 06:19:32.315141 30817 leader_election.cc:304] T 00000000000000000000000000000000 P a822dcc8dab14e098dc5826830e416ff [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: a822dcc8dab14e098dc5826830e416ff; no voters: 
I20260812 06:19:32.315356 30817 leader_election.cc:290] T 00000000000000000000000000000000 P a822dcc8dab14e098dc5826830e416ff [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:32.315555 30822 raft_consensus.cc:2804] T 00000000000000000000000000000000 P a822dcc8dab14e098dc5826830e416ff [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:32.315797 30822 raft_consensus.cc:697] T 00000000000000000000000000000000 P a822dcc8dab14e098dc5826830e416ff [term 1 LEADER]: Becoming Leader. State: Replica: a822dcc8dab14e098dc5826830e416ff, State: Running, Role: LEADER
I20260812 06:19:32.315843 30817 sys_catalog.cc:565] T 00000000000000000000000000000000 P a822dcc8dab14e098dc5826830e416ff [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:32.315943 30822 consensus_queue.cc:237] T 00000000000000000000000000000000 P a822dcc8dab14e098dc5826830e416ff [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: "a822dcc8dab14e098dc5826830e416ff" member_type: VOTER }
I20260812 06:19:32.316488 30823 sys_catalog.cc:455] T 00000000000000000000000000000000 P a822dcc8dab14e098dc5826830e416ff [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "a822dcc8dab14e098dc5826830e416ff" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a822dcc8dab14e098dc5826830e416ff" member_type: VOTER } }
I20260812 06:19:32.316514 30824 sys_catalog.cc:455] T 00000000000000000000000000000000 P a822dcc8dab14e098dc5826830e416ff [sys.catalog]: SysCatalogTable state changed. Reason: New leader a822dcc8dab14e098dc5826830e416ff. Latest consensus state: current_term: 1 leader_uuid: "a822dcc8dab14e098dc5826830e416ff" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "a822dcc8dab14e098dc5826830e416ff" member_type: VOTER } }
I20260812 06:19:32.316694 30824 sys_catalog.cc:458] T 00000000000000000000000000000000 P a822dcc8dab14e098dc5826830e416ff [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:32.316948 30823 sys_catalog.cc:458] T 00000000000000000000000000000000 P a822dcc8dab14e098dc5826830e416ff [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:32.317180 30831 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:32.318076 30831 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:32.318352 30521 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:32.320272 30831 catalog_manager.cc:1383] Generated new cluster ID: a1d72013690a4b709a4fd4e538fc1687
I20260812 06:19:32.320324 30831 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:32.341835 30831 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:32.342406 30831 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:32.348875 30831 catalog_manager.cc:6092] T 00000000000000000000000000000000 P a822dcc8dab14e098dc5826830e416ff: Generated new TSK 0
I20260812 06:19:32.349049 30831 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:32.350926 30521 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:32.353024 30843 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:19:32.353176 30846 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:19:32.353298 30844 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:19:32.353204 30521 server_base.cc:1061] running on GCE node
I20260812 06:19:32.353585 30521 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:32.353628 30521 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:19:32.353645 30521 hybrid_clock.cc:648] HybridClock initialized: now 1786515572353645 us; error 0 us; skew 500 ppm
I20260812 06:19:32.354601 30521 webserver.cc:533] Webserver started at http://127.29.206.65:36557/ using document root <none> and password file <none>
I20260812 06:19:32.354763 30521 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:32.354815 30521 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:32.354867 30521 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:32.355273 30521 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566566673-30521-0/minicluster-data/ts-0-root/instance:
uuid: "c8e8f4709f0d46538497cf67fa01c89f"
format_stamp: "Formatted at 2026-08-12 06:19:32 on dist-test-slave-5l3k"
I20260812 06:19:32.356794 30521 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:32.357774 30851 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:19:32.358112 30521 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:32.358184 30521 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566566673-30521-0/minicluster-data/ts-0-root
uuid: "c8e8f4709f0d46538497cf67fa01c89f"
format_stamp: "Formatted at 2026-08-12 06:19:32 on dist-test-slave-5l3k"
I20260812 06:19:32.358245 30521 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566566673-30521-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566566673-30521-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566566673-30521-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:19:32.364784 30521 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:32.365136 30521 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:32.365417 30521 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:32.365967 30521 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:32.366007 30521 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:32.366077 30521 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:32.366120 30521 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:32.370771 30521 rpc_server.cc:307] RPC server started. Bound to: 127.29.206.65:44291
I20260812 06:19:32.372501 30925 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.29.206.65:44291 every 8 connection(s)
I20260812 06:19:32.383754 30928 heartbeater.cc:344] Connected to a master server at 127.29.206.126:36223
I20260812 06:19:32.383932 30928 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:32.384294 30928 heartbeater.cc:507] Master 127.29.206.126:36223 requested a full tablet report, sending...
I20260812 06:19:32.385048 30774 ts_manager.cc:194] Registered new tserver with Master: c8e8f4709f0d46538497cf67fa01c89f (127.29.206.65:44291)
I20260812 06:19:32.385864 30774 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:43436
I20260812 06:19:32.386065 30521 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.014458919s
I20260812 06:19:32.393905 30774 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:43442:
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:19:32.403234 30884 tablet_service.cc:1511] Processing CreateTablet for tablet 6154aec59b6b4e2899d875f7e7a4407d (DEFAULT_TABLE table=heavy-update-compaction-test [id=91bc15efda4b483bb55a317b7f4d7816]), partition=
I20260812 06:19:32.403569 30884 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 6154aec59b6b4e2899d875f7e7a4407d. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:32.405750 30942 tablet_bootstrap.cc:492] T 6154aec59b6b4e2899d875f7e7a4407d P c8e8f4709f0d46538497cf67fa01c89f: Bootstrap starting.
I20260812 06:19:32.406738 30942 tablet_bootstrap.cc:654] T 6154aec59b6b4e2899d875f7e7a4407d P c8e8f4709f0d46538497cf67fa01c89f: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:32.408079 30942 tablet_bootstrap.cc:492] T 6154aec59b6b4e2899d875f7e7a4407d P c8e8f4709f0d46538497cf67fa01c89f: No bootstrap required, opened a new log
I20260812 06:19:32.408231 30942 ts_tablet_manager.cc:1403] T 6154aec59b6b4e2899d875f7e7a4407d P c8e8f4709f0d46538497cf67fa01c89f: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:19:32.408874 30942 raft_consensus.cc:359] T 6154aec59b6b4e2899d875f7e7a4407d P c8e8f4709f0d46538497cf67fa01c89f [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c8e8f4709f0d46538497cf67fa01c89f" member_type: VOTER last_known_addr { host: "127.29.206.65" port: 44291 } }
I20260812 06:19:32.409005 30942 raft_consensus.cc:385] T 6154aec59b6b4e2899d875f7e7a4407d P c8e8f4709f0d46538497cf67fa01c89f [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:32.409067 30942 raft_consensus.cc:740] T 6154aec59b6b4e2899d875f7e7a4407d P c8e8f4709f0d46538497cf67fa01c89f [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: c8e8f4709f0d46538497cf67fa01c89f, State: Initialized, Role: FOLLOWER
I20260812 06:19:32.409227 30942 consensus_queue.cc:260] T 6154aec59b6b4e2899d875f7e7a4407d P c8e8f4709f0d46538497cf67fa01c89f [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: "c8e8f4709f0d46538497cf67fa01c89f" member_type: VOTER last_known_addr { host: "127.29.206.65" port: 44291 } }
I20260812 06:19:32.409322 30942 raft_consensus.cc:399] T 6154aec59b6b4e2899d875f7e7a4407d P c8e8f4709f0d46538497cf67fa01c89f [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:32.409385 30942 raft_consensus.cc:493] T 6154aec59b6b4e2899d875f7e7a4407d P c8e8f4709f0d46538497cf67fa01c89f [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:32.409444 30942 raft_consensus.cc:3060] T 6154aec59b6b4e2899d875f7e7a4407d P c8e8f4709f0d46538497cf67fa01c89f [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:32.410266 30942 raft_consensus.cc:515] T 6154aec59b6b4e2899d875f7e7a4407d P c8e8f4709f0d46538497cf67fa01c89f [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c8e8f4709f0d46538497cf67fa01c89f" member_type: VOTER last_known_addr { host: "127.29.206.65" port: 44291 } }
I20260812 06:19:32.410423 30942 leader_election.cc:304] T 6154aec59b6b4e2899d875f7e7a4407d P c8e8f4709f0d46538497cf67fa01c89f [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: c8e8f4709f0d46538497cf67fa01c89f; no voters: 
I20260812 06:19:32.410691 30942 leader_election.cc:290] T 6154aec59b6b4e2899d875f7e7a4407d P c8e8f4709f0d46538497cf67fa01c89f [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:32.410857 30944 raft_consensus.cc:2804] T 6154aec59b6b4e2899d875f7e7a4407d P c8e8f4709f0d46538497cf67fa01c89f [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:32.411075 30944 raft_consensus.cc:697] T 6154aec59b6b4e2899d875f7e7a4407d P c8e8f4709f0d46538497cf67fa01c89f [term 1 LEADER]: Becoming Leader. State: Replica: c8e8f4709f0d46538497cf67fa01c89f, State: Running, Role: LEADER
I20260812 06:19:32.411068 30928 heartbeater.cc:499] Master 127.29.206.126:36223 was elected leader, sending a full tablet report...
I20260812 06:19:32.411053 30942 ts_tablet_manager.cc:1434] T 6154aec59b6b4e2899d875f7e7a4407d P c8e8f4709f0d46538497cf67fa01c89f: Time spent starting tablet: real 0.003s	user 0.001s	sys 0.002s
I20260812 06:19:32.411429 30944 consensus_queue.cc:237] T 6154aec59b6b4e2899d875f7e7a4407d P c8e8f4709f0d46538497cf67fa01c89f [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: "c8e8f4709f0d46538497cf67fa01c89f" member_type: VOTER last_known_addr { host: "127.29.206.65" port: 44291 } }
I20260812 06:19:32.413050 30774 catalog_manager.cc:5719] T 6154aec59b6b4e2899d875f7e7a4407d P c8e8f4709f0d46538497cf67fa01c89f reported cstate change: term changed from 0 to 1, leader changed from <none> to c8e8f4709f0d46538497cf67fa01c89f (127.29.206.65). New cstate: current_term: 1 leader_uuid: "c8e8f4709f0d46538497cf67fa01c89f" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c8e8f4709f0d46538497cf67fa01c89f" member_type: VOTER last_known_addr { host: "127.29.206.65" port: 44291 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:32.473861 30521 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.054s	user 0.015s	sys 0.008s
I20260812 06:19:32.622984 30929 maintenance_manager.cc:419] P c8e8f4709f0d46538497cf67fa01c89f: Scheduling FlushMRSOp(6154aec59b6b4e2899d875f7e7a4407d): perf score=19.054940
I20260812 06:19:32.784391 30856 maintenance_manager.cc:643] P c8e8f4709f0d46538497cf67fa01c89f: FlushMRSOp(6154aec59b6b4e2899d875f7e7a4407d) complete. Timing: real 0.161s	user 0.103s	sys 0.056s Metrics: {"bytes_written":12717735,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":93,"dirs.run_cpu_time_us":200,"dirs.run_wall_time_us":1037,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":37655,"lbm_writes_lt_1ms":767,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":7424,"update_count":1550}
I20260812 06:19:32.785522 30929 maintenance_manager.cc:419] P c8e8f4709f0d46538497cf67fa01c89f: Scheduling LogGCOp(6154aec59b6b4e2899d875f7e7a4407d): free 20290830 bytes of WAL
I20260812 06:19:32.785804 30856 log_reader.cc:385] T 6154aec59b6b4e2899d875f7e7a4407d: removed 2 log segments from log reader
I20260812 06:19:32.785853 30856 log.cc:1079] T 6154aec59b6b4e2899d875f7e7a4407d P c8e8f4709f0d46538497cf67fa01c89f: Deleting log segment in path: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566566673-30521-0/minicluster-data/ts-0-root/wals/6154aec59b6b4e2899d875f7e7a4407d/wal-000000001 (ops 1-6)
I20260812 06:19:32.785884 30856 log.cc:1079] T 6154aec59b6b4e2899d875f7e7a4407d P c8e8f4709f0d46538497cf67fa01c89f: Deleting log segment in path: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566566673-30521-0/minicluster-data/ts-0-root/wals/6154aec59b6b4e2899d875f7e7a4407d/wal-000000002 (ops 7-10)
I20260812 06:19:32.790729 30856 maintenance_manager.cc:643] P c8e8f4709f0d46538497cf67fa01c89f: LogGCOp(6154aec59b6b4e2899d875f7e7a4407d) complete. Timing: real 0.005s	user 0.000s	sys 0.005s Metrics: {}
I20260812 06:19:32.791154 30929 maintenance_manager.cc:419] P c8e8f4709f0d46538497cf67fa01c89f: Scheduling FlushDeltaMemStoresOp(6154aec59b6b4e2899d875f7e7a4407d): perf score=2.188937
I20260812 06:19:32.804665 30856 maintenance_manager.cc:643] P c8e8f4709f0d46538497cf67fa01c89f: FlushDeltaMemStoresOp(6154aec59b6b4e2899d875f7e7a4407d) complete. Timing: real 0.013s	user 0.004s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4644,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:32.805197 30929 maintenance_manager.cc:419] P c8e8f4709f0d46538497cf67fa01c89f: Scheduling MajorDeltaCompactionOp(6154aec59b6b4e2899d875f7e7a4407d): perf score=1.000000
I20260812 06:19:32.961529 30856 maintenance_manager.cc:643] P c8e8f4709f0d46538497cf67fa01c89f: MajorDeltaCompactionOp(6154aec59b6b4e2899d875f7e7a4407d) complete. Timing: real 0.156s	user 0.116s	sys 0.039s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":318,"lbm_read_time_us":10508,"lbm_reads_lt_1ms":464,"lbm_write_time_us":27197,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"thread_start_us":327,"threads_started":5,"update_count":2000}
I20260812 06:19:32.962174 30929 maintenance_manager.cc:419] P c8e8f4709f0d46538497cf67fa01c89f: Scheduling UndoDeltaBlockGCOp(6154aec59b6b4e2899d875f7e7a4407d): 16411393 bytes on disk
I20260812 06:19:32.962733 30856 maintenance_manager.cc:643] P c8e8f4709f0d46538497cf67fa01c89f: UndoDeltaBlockGCOp(6154aec59b6b4e2899d875f7e7a4407d) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":85,"lbm_reads_lt_1ms":4}
I20260812 06:19:32.963274 30929 maintenance_manager.cc:419] P c8e8f4709f0d46538497cf67fa01c89f: Scheduling FlushDeltaMemStoresOp(6154aec59b6b4e2899d875f7e7a4407d): perf score=10.126437
I20260812 06:19:32.999845 30856 maintenance_manager.cc:643] P c8e8f4709f0d46538497cf67fa01c89f: FlushDeltaMemStoresOp(6154aec59b6b4e2899d875f7e7a4407d) complete. Timing: real 0.036s	user 0.021s	sys 0.011s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14245,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:33.000566 30929 maintenance_manager.cc:419] P c8e8f4709f0d46538497cf67fa01c89f: Scheduling FlushDeltaMemStoresOp(6154aec59b6b4e2899d875f7e7a4407d): perf score=2.188937
I20260812 06:19:33.011694 30856 maintenance_manager.cc:643] P c8e8f4709f0d46538497cf67fa01c89f: FlushDeltaMemStoresOp(6154aec59b6b4e2899d875f7e7a4407d) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4151,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:33.012248 30929 maintenance_manager.cc:419] P c8e8f4709f0d46538497cf67fa01c89f: Scheduling MajorDeltaCompactionOp(6154aec59b6b4e2899d875f7e7a4407d): perf score=1.000000
I20260812 06:19:33.149545 30856 maintenance_manager.cc:643] P c8e8f4709f0d46538497cf67fa01c89f: MajorDeltaCompactionOp(6154aec59b6b4e2899d875f7e7a4407d) complete. Timing: real 0.137s	user 0.101s	sys 0.036s 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":920,"lbm_read_time_us":9251,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25041,"lbm_writes_lt_1ms":443,"mutex_wait_us":27,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":23936,"update_count":2000}
I20260812 06:19:33.150187 30929 maintenance_manager.cc:419] P c8e8f4709f0d46538497cf67fa01c89f: Scheduling FlushDeltaMemStoresOp(6154aec59b6b4e2899d875f7e7a4407d): perf score=10.126437
I20260812 06:19:33.190006 30856 maintenance_manager.cc:643] P c8e8f4709f0d46538497cf67fa01c89f: FlushDeltaMemStoresOp(6154aec59b6b4e2899d875f7e7a4407d) complete. Timing: real 0.040s	user 0.019s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16363,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:33.190631 30929 maintenance_manager.cc:419] P c8e8f4709f0d46538497cf67fa01c89f: Scheduling FlushDeltaMemStoresOp(6154aec59b6b4e2899d875f7e7a4407d): perf score=2.188937
I20260812 06:19:33.203253 30856 maintenance_manager.cc:643] P c8e8f4709f0d46538497cf67fa01c89f: FlushDeltaMemStoresOp(6154aec59b6b4e2899d875f7e7a4407d) complete. Timing: real 0.012s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4309,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:33.204087 30929 maintenance_manager.cc:419] P c8e8f4709f0d46538497cf67fa01c89f: Scheduling MajorDeltaCompactionOp(6154aec59b6b4e2899d875f7e7a4407d): perf score=1.000000
I20260812 06:19:33.336519 30856 maintenance_manager.cc:643] P c8e8f4709f0d46538497cf67fa01c89f: MajorDeltaCompactionOp(6154aec59b6b4e2899d875f7e7a4407d) complete. Timing: real 0.132s	user 0.108s	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":342,"lbm_read_time_us":10122,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25789,"lbm_writes_lt_1ms":443,"mutex_wait_us":67,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":13824,"update_count":2000}
I20260812 06:19:33.337234 30929 maintenance_manager.cc:419] P c8e8f4709f0d46538497cf67fa01c89f: Scheduling FlushDeltaMemStoresOp(6154aec59b6b4e2899d875f7e7a4407d): perf score=10.126437
I20260812 06:19:33.384366 30856 maintenance_manager.cc:643] P c8e8f4709f0d46538497cf67fa01c89f: FlushDeltaMemStoresOp(6154aec59b6b4e2899d875f7e7a4407d) complete. Timing: real 0.047s	user 0.022s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13587,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:33.384896 30929 maintenance_manager.cc:419] P c8e8f4709f0d46538497cf67fa01c89f: Scheduling FlushDeltaMemStoresOp(6154aec59b6b4e2899d875f7e7a4407d): perf score=2.188937
I20260812 06:19:33.397078 30856 maintenance_manager.cc:643] P c8e8f4709f0d46538497cf67fa01c89f: FlushDeltaMemStoresOp(6154aec59b6b4e2899d875f7e7a4407d) complete. Timing: real 0.012s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4221,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:33.397642 30929 maintenance_manager.cc:419] P c8e8f4709f0d46538497cf67fa01c89f: Scheduling MajorDeltaCompactionOp(6154aec59b6b4e2899d875f7e7a4407d): perf score=1.000000
I20260812 06:19:33.529770 30856 maintenance_manager.cc:643] P c8e8f4709f0d46538497cf67fa01c89f: MajorDeltaCompactionOp(6154aec59b6b4e2899d875f7e7a4407d) complete. Timing: real 0.132s	user 0.091s	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":1241,"lbm_read_time_us":9426,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24147,"lbm_writes_lt_1ms":443,"mutex_wait_us":303,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9088,"update_count":2000}
I20260812 06:19:33.530535 30929 maintenance_manager.cc:419] P c8e8f4709f0d46538497cf67fa01c89f: Scheduling FlushDeltaMemStoresOp(6154aec59b6b4e2899d875f7e7a4407d): perf score=10.126437
I20260812 06:19:33.577428 30856 maintenance_manager.cc:643] P c8e8f4709f0d46538497cf67fa01c89f: FlushDeltaMemStoresOp(6154aec59b6b4e2899d875f7e7a4407d) complete. Timing: real 0.047s	user 0.015s	sys 0.028s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15427,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:19:33.578001 30929 maintenance_manager.cc:419] P c8e8f4709f0d46538497cf67fa01c89f: Scheduling FlushDeltaMemStoresOp(6154aec59b6b4e2899d875f7e7a4407d): perf score=2.188937
I20260812 06:19:33.590574 30856 maintenance_manager.cc:643] P c8e8f4709f0d46538497cf67fa01c89f: FlushDeltaMemStoresOp(6154aec59b6b4e2899d875f7e7a4407d) complete. Timing: real 0.012s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4903,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:33.591055 30929 maintenance_manager.cc:419] P c8e8f4709f0d46538497cf67fa01c89f: Scheduling MajorDeltaCompactionOp(6154aec59b6b4e2899d875f7e7a4407d): perf score=1.000000
I20260812 06:19:33.746361 30856 maintenance_manager.cc:643] P c8e8f4709f0d46538497cf67fa01c89f: MajorDeltaCompactionOp(6154aec59b6b4e2899d875f7e7a4407d) complete. Timing: real 0.155s	user 0.087s	sys 0.068s 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":588,"lbm_read_time_us":9585,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26218,"lbm_writes_lt_1ms":443,"mutex_wait_us":19,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":8832,"update_count":2000}
I20260812 06:19:33.747162 30929 maintenance_manager.cc:419] P c8e8f4709f0d46538497cf67fa01c89f: Scheduling FlushDeltaMemStoresOp(6154aec59b6b4e2899d875f7e7a4407d): perf score=10.126437
I20260812 06:19:33.794039 30856 maintenance_manager.cc:643] P c8e8f4709f0d46538497cf67fa01c89f: FlushDeltaMemStoresOp(6154aec59b6b4e2899d875f7e7a4407d) complete. Timing: real 0.047s	user 0.031s	sys 0.012s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":18644,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:33.794834 30929 maintenance_manager.cc:419] P c8e8f4709f0d46538497cf67fa01c89f: Scheduling FlushDeltaMemStoresOp(6154aec59b6b4e2899d875f7e7a4407d): perf score=2.188937
I20260812 06:19:33.823232 30856 maintenance_manager.cc:643] P c8e8f4709f0d46538497cf67fa01c89f: FlushDeltaMemStoresOp(6154aec59b6b4e2899d875f7e7a4407d) complete. Timing: real 0.028s	user 0.003s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4893,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:33.823776 30929 maintenance_manager.cc:419] P c8e8f4709f0d46538497cf67fa01c89f: Scheduling FlushDeltaMemStoresOp(6154aec59b6b4e2899d875f7e7a4407d): perf score=2.188937
I20260812 06:19:33.834388 30856 maintenance_manager.cc:643] P c8e8f4709f0d46538497cf67fa01c89f: FlushDeltaMemStoresOp(6154aec59b6b4e2899d875f7e7a4407d) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4006,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:33.834955 30929 maintenance_manager.cc:419] P c8e8f4709f0d46538497cf67fa01c89f: Scheduling MajorDeltaCompactionOp(6154aec59b6b4e2899d875f7e7a4407d): perf score=1.000000
I20260812 06:19:33.990974 30856 maintenance_manager.cc:643] P c8e8f4709f0d46538497cf67fa01c89f: MajorDeltaCompactionOp(6154aec59b6b4e2899d875f7e7a4407d) complete. Timing: real 0.156s	user 0.112s	sys 0.037s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774808,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":713,"lbm_read_time_us":10515,"lbm_reads_lt_1ms":573,"lbm_write_time_us":29808,"lbm_writes_lt_1ms":543,"mutex_wait_us":314,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8064,"update_count":2500}
I20260812 06:19:33.991576 30929 maintenance_manager.cc:419] P c8e8f4709f0d46538497cf67fa01c89f: Scheduling FlushDeltaMemStoresOp(6154aec59b6b4e2899d875f7e7a4407d): perf score=11.118625
I20260812 06:19:34.029366 30856 maintenance_manager.cc:643] P c8e8f4709f0d46538497cf67fa01c89f: FlushDeltaMemStoresOp(6154aec59b6b4e2899d875f7e7a4407d) complete. Timing: real 0.038s	user 0.029s	sys 0.005s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":16271,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:34.029901 30929 maintenance_manager.cc:419] P c8e8f4709f0d46538497cf67fa01c89f: Scheduling FlushDeltaMemStoresOp(6154aec59b6b4e2899d875f7e7a4407d): perf score=2.188937
I20260812 06:19:34.045064 30856 maintenance_manager.cc:643] P c8e8f4709f0d46538497cf67fa01c89f: FlushDeltaMemStoresOp(6154aec59b6b4e2899d875f7e7a4407d) complete. Timing: real 0.015s	user 0.009s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5725,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:34.045818 30929 maintenance_manager.cc:419] P c8e8f4709f0d46538497cf67fa01c89f: Scheduling FlushMRSOp(6154aec59b6b4e2899d875f7e7a4407d): perf score=1.000000
I20260812 06:19:34.098937 30856 maintenance_manager.cc:643] P c8e8f4709f0d46538497cf67fa01c89f: FlushMRSOp(6154aec59b6b4e2899d875f7e7a4407d) complete. Timing: real 0.053s	user 0.031s	sys 0.000s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":71,"dirs.run_cpu_time_us":296,"dirs.run_wall_time_us":1589,"drs_written":1,"lbm_read_time_us":41,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2297,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:19:34.099691 30929 maintenance_manager.cc:419] P c8e8f4709f0d46538497cf67fa01c89f: Scheduling LogGCOp(6154aec59b6b4e2899d875f7e7a4407d): free 112692309 bytes of WAL
I20260812 06:19:34.099949 30856 log_reader.cc:385] T 6154aec59b6b4e2899d875f7e7a4407d: removed 11 log segments from log reader
I20260812 06:19:34.100020 30856 log.cc:1079] T 6154aec59b6b4e2899d875f7e7a4407d P c8e8f4709f0d46538497cf67fa01c89f: Deleting log segment in path: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566566673-30521-0/minicluster-data/ts-0-root/wals/6154aec59b6b4e2899d875f7e7a4407d/wal-000000003 (ops 11-15)
I20260812 06:19:34.100082 30856 log.cc:1079] T 6154aec59b6b4e2899d875f7e7a4407d P c8e8f4709f0d46538497cf67fa01c89f: Deleting log segment in path: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566566673-30521-0/minicluster-data/ts-0-root/wals/6154aec59b6b4e2899d875f7e7a4407d/wal-000000004 (ops 16-20)
I20260812 06:19:34.100147 30856 log.cc:1079] T 6154aec59b6b4e2899d875f7e7a4407d P c8e8f4709f0d46538497cf67fa01c89f: Deleting log segment in path: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566566673-30521-0/minicluster-data/ts-0-root/wals/6154aec59b6b4e2899d875f7e7a4407d/wal-000000005 (ops 21-25)
I20260812 06:19:34.100195 30856 log.cc:1079] T 6154aec59b6b4e2899d875f7e7a4407d P c8e8f4709f0d46538497cf67fa01c89f: Deleting log segment in path: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566566673-30521-0/minicluster-data/ts-0-root/wals/6154aec59b6b4e2899d875f7e7a4407d/wal-000000006 (ops 26-30)
I20260812 06:19:34.100239 30856 log.cc:1079] T 6154aec59b6b4e2899d875f7e7a4407d P c8e8f4709f0d46538497cf67fa01c89f: Deleting log segment in path: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566566673-30521-0/minicluster-data/ts-0-root/wals/6154aec59b6b4e2899d875f7e7a4407d/wal-000000007 (ops 31-35)
I20260812 06:19:34.100284 30856 log.cc:1079] T 6154aec59b6b4e2899d875f7e7a4407d P c8e8f4709f0d46538497cf67fa01c89f: Deleting log segment in path: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566566673-30521-0/minicluster-data/ts-0-root/wals/6154aec59b6b4e2899d875f7e7a4407d/wal-000000008 (ops 36-40)
I20260812 06:19:34.100329 30856 log.cc:1079] T 6154aec59b6b4e2899d875f7e7a4407d P c8e8f4709f0d46538497cf67fa01c89f: Deleting log segment in path: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566566673-30521-0/minicluster-data/ts-0-root/wals/6154aec59b6b4e2899d875f7e7a4407d/wal-000000009 (ops 41-45)
I20260812 06:19:34.100382 30856 log.cc:1079] T 6154aec59b6b4e2899d875f7e7a4407d P c8e8f4709f0d46538497cf67fa01c89f: Deleting log segment in path: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566566673-30521-0/minicluster-data/ts-0-root/wals/6154aec59b6b4e2899d875f7e7a4407d/wal-000000010 (ops 46-50)
I20260812 06:19:34.100430 30856 log.cc:1079] T 6154aec59b6b4e2899d875f7e7a4407d P c8e8f4709f0d46538497cf67fa01c89f: Deleting log segment in path: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566566673-30521-0/minicluster-data/ts-0-root/wals/6154aec59b6b4e2899d875f7e7a4407d/wal-000000011 (ops 51-55)
I20260812 06:19:34.100481 30856 log.cc:1079] T 6154aec59b6b4e2899d875f7e7a4407d P c8e8f4709f0d46538497cf67fa01c89f: Deleting log segment in path: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566566673-30521-0/minicluster-data/ts-0-root/wals/6154aec59b6b4e2899d875f7e7a4407d/wal-000000012 (ops 56-60)
I20260812 06:19:34.100529 30856 log.cc:1079] T 6154aec59b6b4e2899d875f7e7a4407d P c8e8f4709f0d46538497cf67fa01c89f: Deleting log segment in path: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566566673-30521-0/minicluster-data/ts-0-root/wals/6154aec59b6b4e2899d875f7e7a4407d/wal-000000013 (ops 61-65)
I20260812 06:19:34.126574 30856 maintenance_manager.cc:643] P c8e8f4709f0d46538497cf67fa01c89f: LogGCOp(6154aec59b6b4e2899d875f7e7a4407d) complete. Timing: real 0.027s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:19:34.127009 30929 maintenance_manager.cc:419] P c8e8f4709f0d46538497cf67fa01c89f: Scheduling FlushDeltaMemStoresOp(6154aec59b6b4e2899d875f7e7a4407d): perf score=7.149875
I20260812 06:19:34.160405 30856 maintenance_manager.cc:643] P c8e8f4709f0d46538497cf67fa01c89f: FlushDeltaMemStoresOp(6154aec59b6b4e2899d875f7e7a4407d) complete. Timing: real 0.033s	user 0.011s	sys 0.020s Metrics: {"bytes_written":8615323,"delete_count":0,"lbm_write_time_us":8907,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:19:34.161088 30929 maintenance_manager.cc:419] P c8e8f4709f0d46538497cf67fa01c89f: Scheduling LogGCOp(6154aec59b6b4e2899d875f7e7a4407d): free 12017983 bytes of WAL
I20260812 06:19:34.161358 30856 log_reader.cc:385] T 6154aec59b6b4e2899d875f7e7a4407d: removed 1 log segments from log reader
I20260812 06:19:34.161414 30856 log.cc:1079] T 6154aec59b6b4e2899d875f7e7a4407d P c8e8f4709f0d46538497cf67fa01c89f: Deleting log segment in path: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566566673-30521-0/minicluster-data/ts-0-root/wals/6154aec59b6b4e2899d875f7e7a4407d/wal-000000014 (ops 66-70)
I20260812 06:19:34.164047 30856 maintenance_manager.cc:643] P c8e8f4709f0d46538497cf67fa01c89f: LogGCOp(6154aec59b6b4e2899d875f7e7a4407d) complete. Timing: real 0.003s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:19:34.164490 30929 maintenance_manager.cc:419] P c8e8f4709f0d46538497cf67fa01c89f: Scheduling FlushDeltaMemStoresOp(6154aec59b6b4e2899d875f7e7a4407d): perf score=2.188937
I20260812 06:19:34.176520 30856 maintenance_manager.cc:643] P c8e8f4709f0d46538497cf67fa01c89f: FlushDeltaMemStoresOp(6154aec59b6b4e2899d875f7e7a4407d) complete. Timing: real 0.012s	user 0.009s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3956,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:34.177299 30929 maintenance_manager.cc:419] P c8e8f4709f0d46538497cf67fa01c89f: Scheduling UndoDeltaBlockGCOp(6154aec59b6b4e2899d875f7e7a4407d): 472 bytes on disk
I20260812 06:19:34.177824 30856 maintenance_manager.cc:643] P c8e8f4709f0d46538497cf67fa01c89f: UndoDeltaBlockGCOp(6154aec59b6b4e2899d875f7e7a4407d) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":92,"lbm_reads_lt_1ms":4}
I20260812 06:19:34.178537 30929 maintenance_manager.cc:419] P c8e8f4709f0d46538497cf67fa01c89f: Scheduling MajorDeltaCompactionOp(6154aec59b6b4e2899d875f7e7a4407d): perf score=1.000000
I20260812 06:19:34.435563 30856 maintenance_manager.cc:643] P c8e8f4709f0d46538497cf67fa01c89f: MajorDeltaCompactionOp(6154aec59b6b4e2899d875f7e7a4407d) complete. Timing: real 0.257s	user 0.136s	sys 0.120s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979735,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":541,"lbm_read_time_us":18217,"lbm_reads_lt_1ms":774,"lbm_write_time_us":41196,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":3072,"thread_start_us":86,"threads_started":1,"update_count":3500}
I20260812 06:19:34.436903 30929 maintenance_manager.cc:419] P c8e8f4709f0d46538497cf67fa01c89f: Scheduling FlushDeltaMemStoresOp(6154aec59b6b4e2899d875f7e7a4407d): perf score=18.063937
I20260812 06:19:34.515928 30856 maintenance_manager.cc:643] P c8e8f4709f0d46538497cf67fa01c89f: FlushDeltaMemStoresOp(6154aec59b6b4e2899d875f7e7a4407d) complete. Timing: real 0.079s	user 0.041s	sys 0.035s Metrics: {"bytes_written":20512318,"delete_count":0,"lbm_write_time_us":37907,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":500,"reinsert_count":0,"update_count":2500}
I20260812 06:19:34.516669 30929 maintenance_manager.cc:419] P c8e8f4709f0d46538497cf67fa01c89f: Scheduling FlushDeltaMemStoresOp(6154aec59b6b4e2899d875f7e7a4407d): perf score=2.188937
I20260812 06:19:34.546348 30856 maintenance_manager.cc:643] P c8e8f4709f0d46538497cf67fa01c89f: FlushDeltaMemStoresOp(6154aec59b6b4e2899d875f7e7a4407d) complete. Timing: real 0.029s	user 0.004s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":7159,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:34.546927 30929 maintenance_manager.cc:419] P c8e8f4709f0d46538497cf67fa01c89f: Scheduling FlushDeltaMemStoresOp(6154aec59b6b4e2899d875f7e7a4407d): perf score=2.188937
I20260812 06:19:34.557667 30856 maintenance_manager.cc:643] P c8e8f4709f0d46538497cf67fa01c89f: FlushDeltaMemStoresOp(6154aec59b6b4e2899d875f7e7a4407d) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4139,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:34.558238 30929 maintenance_manager.cc:419] P c8e8f4709f0d46538497cf67fa01c89f: Scheduling MajorDeltaCompactionOp(6154aec59b6b4e2899d875f7e7a4407d): perf score=1.000000
I20260812 06:19:34.791262 30856 maintenance_manager.cc:643] P c8e8f4709f0d46538497cf67fa01c89f: MajorDeltaCompactionOp(6154aec59b6b4e2899d875f7e7a4407d) complete. Timing: real 0.233s	user 0.181s	sys 0.051s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":32979636,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":263,"lbm_read_time_us":16598,"lbm_reads_lt_1ms":773,"lbm_write_time_us":42682,"lbm_writes_lt_1ms":743,"mutex_wait_us":99,"peak_mem_usage":87969044,"reinsert_count":0,"update_count":3500}
I20260812 06:19:34.791954 30929 maintenance_manager.cc:419] P c8e8f4709f0d46538497cf67fa01c89f: Scheduling FlushDeltaMemStoresOp(6154aec59b6b4e2899d875f7e7a4407d): perf score=18.063937
I20260812 06:19:34.856084 30856 maintenance_manager.cc:643] P c8e8f4709f0d46538497cf67fa01c89f: FlushDeltaMemStoresOp(6154aec59b6b4e2899d875f7e7a4407d) complete. Timing: real 0.064s	user 0.029s	sys 0.032s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":27033,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:34.857182 30929 maintenance_manager.cc:419] P c8e8f4709f0d46538497cf67fa01c89f: Scheduling FlushDeltaMemStoresOp(6154aec59b6b4e2899d875f7e7a4407d): perf score=2.188937
I20260812 06:19:34.878075 30856 maintenance_manager.cc:643] P c8e8f4709f0d46538497cf67fa01c89f: FlushDeltaMemStoresOp(6154aec59b6b4e2899d875f7e7a4407d) complete. Timing: real 0.021s	user 0.007s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6041,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:34.878643 30929 maintenance_manager.cc:419] P c8e8f4709f0d46538497cf67fa01c89f: Scheduling FlushDeltaMemStoresOp(6154aec59b6b4e2899d875f7e7a4407d): perf score=2.188937
I20260812 06:19:34.889626 30856 maintenance_manager.cc:643] P c8e8f4709f0d46538497cf67fa01c89f: FlushDeltaMemStoresOp(6154aec59b6b4e2899d875f7e7a4407d) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4217,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:34.890108 30929 maintenance_manager.cc:419] P c8e8f4709f0d46538497cf67fa01c89f: Scheduling MajorDeltaCompactionOp(6154aec59b6b4e2899d875f7e7a4407d): perf score=1.000000
I20260812 06:19:35.094781 30856 maintenance_manager.cc:643] P c8e8f4709f0d46538497cf67fa01c89f: MajorDeltaCompactionOp(6154aec59b6b4e2899d875f7e7a4407d) complete. Timing: real 0.204s	user 0.160s	sys 0.044s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":32979633,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":727,"lbm_read_time_us":13877,"lbm_reads_lt_1ms":773,"lbm_write_time_us":43552,"lbm_writes_lt_1ms":743,"mutex_wait_us":73,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":32256,"update_count":3500}
I20260812 06:19:35.099470 30929 maintenance_manager.cc:419] P c8e8f4709f0d46538497cf67fa01c89f: Scheduling FlushDeltaMemStoresOp(6154aec59b6b4e2899d875f7e7a4407d): perf score=15.087375
I20260812 06:19:35.144064 30856 maintenance_manager.cc:643] P c8e8f4709f0d46538497cf67fa01c89f: FlushDeltaMemStoresOp(6154aec59b6b4e2899d875f7e7a4407d) complete. Timing: real 0.044s	user 0.027s	sys 0.015s Metrics: {"bytes_written":16820139,"delete_count":0,"lbm_write_time_us":18649,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:19:35.144727 30929 maintenance_manager.cc:419] P c8e8f4709f0d46538497cf67fa01c89f: Scheduling FlushDeltaMemStoresOp(6154aec59b6b4e2899d875f7e7a4407d): perf score=2.188937
I20260812 06:19:35.168655 30856 maintenance_manager.cc:643] P c8e8f4709f0d46538497cf67fa01c89f: FlushDeltaMemStoresOp(6154aec59b6b4e2899d875f7e7a4407d) complete. Timing: real 0.024s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4603,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:35.169250 30929 maintenance_manager.cc:419] P c8e8f4709f0d46538497cf67fa01c89f: Scheduling FlushDeltaMemStoresOp(6154aec59b6b4e2899d875f7e7a4407d): perf score=2.188937
I20260812 06:19:35.180384 30856 maintenance_manager.cc:643] P c8e8f4709f0d46538497cf67fa01c89f: FlushDeltaMemStoresOp(6154aec59b6b4e2899d875f7e7a4407d) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4162,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:35.180995 30929 maintenance_manager.cc:419] P c8e8f4709f0d46538497cf67fa01c89f: Scheduling MajorDeltaCompactionOp(6154aec59b6b4e2899d875f7e7a4407d): perf score=1.000000
I20260812 06:19:35.345755 30856 maintenance_manager.cc:643] P c8e8f4709f0d46538497cf67fa01c89f: MajorDeltaCompactionOp(6154aec59b6b4e2899d875f7e7a4407d) complete. Timing: real 0.165s	user 0.149s	sys 0.015s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877203,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":976,"lbm_read_time_us":13229,"lbm_reads_lt_1ms":673,"lbm_write_time_us":31600,"lbm_writes_lt_1ms":643,"mutex_wait_us":340,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":7040,"update_count":3000}
I20260812 06:19:35.346522 30929 maintenance_manager.cc:419] P c8e8f4709f0d46538497cf67fa01c89f: Scheduling FlushDeltaMemStoresOp(6154aec59b6b4e2899d875f7e7a4407d): perf score=14.095187
I20260812 06:19:35.401834 30856 maintenance_manager.cc:643] P c8e8f4709f0d46538497cf67fa01c89f: FlushDeltaMemStoresOp(6154aec59b6b4e2899d875f7e7a4407d) complete. Timing: real 0.055s	user 0.026s	sys 0.025s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":24493,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:35.402354 30929 maintenance_manager.cc:419] P c8e8f4709f0d46538497cf67fa01c89f: Scheduling FlushDeltaMemStoresOp(6154aec59b6b4e2899d875f7e7a4407d): perf score=2.188937
I20260812 06:19:35.413791 30856 maintenance_manager.cc:643] P c8e8f4709f0d46538497cf67fa01c89f: FlushDeltaMemStoresOp(6154aec59b6b4e2899d875f7e7a4407d) complete. Timing: real 0.011s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4388,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:35.414420 30929 maintenance_manager.cc:419] P c8e8f4709f0d46538497cf67fa01c89f: Scheduling MajorDeltaCompactionOp(6154aec59b6b4e2899d875f7e7a4407d): perf score=1.000000
I20260812 06:19:35.580911 30856 maintenance_manager.cc:643] P c8e8f4709f0d46538497cf67fa01c89f: MajorDeltaCompactionOp(6154aec59b6b4e2899d875f7e7a4407d) complete. Timing: real 0.166s	user 0.130s	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":1131,"lbm_read_time_us":11862,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30800,"lbm_writes_lt_1ms":543,"mutex_wait_us":333,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13184,"update_count":2500}
I20260812 06:19:35.581813 30929 maintenance_manager.cc:419] P c8e8f4709f0d46538497cf67fa01c89f: Scheduling FlushDeltaMemStoresOp(6154aec59b6b4e2899d875f7e7a4407d): perf score=12.110812
I20260812 06:19:35.624969 30856 maintenance_manager.cc:643] P c8e8f4709f0d46538497cf67fa01c89f: FlushDeltaMemStoresOp(6154aec59b6b4e2899d875f7e7a4407d) complete. Timing: real 0.043s	user 0.025s	sys 0.015s Metrics: {"bytes_written":13866410,"delete_count":0,"lbm_write_time_us":18445,"lbm_writes_lt_1ms":341,"reinsert_count":0,"update_count":1690}
I20260812 06:19:35.625583 30929 maintenance_manager.cc:419] P c8e8f4709f0d46538497cf67fa01c89f: Scheduling FlushDeltaMemStoresOp(6154aec59b6b4e2899d875f7e7a4407d): perf score=1.196750
I20260812 06:19:35.633677 30856 maintenance_manager.cc:643] P c8e8f4709f0d46538497cf67fa01c89f: FlushDeltaMemStoresOp(6154aec59b6b4e2899d875f7e7a4407d) complete. Timing: real 0.008s	user 0.006s	sys 0.000s Metrics: {"bytes_written":2543704,"delete_count":0,"lbm_write_time_us":2643,"lbm_writes_lt_1ms":65,"reinsert_count":0,"update_count":310}
I20260812 06:19:35.634395 30929 maintenance_manager.cc:419] P c8e8f4709f0d46538497cf67fa01c89f: Scheduling FlushMRSOp(6154aec59b6b4e2899d875f7e7a4407d): perf score=1.000000
I20260812 06:19:35.672135 30856 maintenance_manager.cc:643] P c8e8f4709f0d46538497cf67fa01c89f: FlushMRSOp(6154aec59b6b4e2899d875f7e7a4407d) complete. Timing: real 0.037s	user 0.033s	sys 0.002s Metrics: {"bytes_written":1316419,"cfile_init":1,"dirs.queue_time_us":94,"dirs.run_cpu_time_us":237,"dirs.run_wall_time_us":2044,"drs_written":1,"lbm_read_time_us":41,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1785,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:19:35.672822 30929 maintenance_manager.cc:419] P c8e8f4709f0d46538497cf67fa01c89f: Scheduling LogGCOp(6154aec59b6b4e2899d875f7e7a4407d): free 129320468 bytes of WAL
I20260812 06:19:35.673094 30856 log_reader.cc:385] T 6154aec59b6b4e2899d875f7e7a4407d: removed 13 log segments from log reader
I20260812 06:19:35.673141 30856 log.cc:1079] T 6154aec59b6b4e2899d875f7e7a4407d P c8e8f4709f0d46538497cf67fa01c89f: Deleting log segment in path: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566566673-30521-0/minicluster-data/ts-0-root/wals/6154aec59b6b4e2899d875f7e7a4407d/wal-000000015 (ops 71-75)
I20260812 06:19:35.673171 30856 log.cc:1079] T 6154aec59b6b4e2899d875f7e7a4407d P c8e8f4709f0d46538497cf67fa01c89f: Deleting log segment in path: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566566673-30521-0/minicluster-data/ts-0-root/wals/6154aec59b6b4e2899d875f7e7a4407d/wal-000000016 (ops 76-80)
I20260812 06:19:35.673237 30856 log.cc:1079] T 6154aec59b6b4e2899d875f7e7a4407d P c8e8f4709f0d46538497cf67fa01c89f: Deleting log segment in path: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566566673-30521-0/minicluster-data/ts-0-root/wals/6154aec59b6b4e2899d875f7e7a4407d/wal-000000017 (ops 81-85)
I20260812 06:19:35.673280 30856 log.cc:1079] T 6154aec59b6b4e2899d875f7e7a4407d P c8e8f4709f0d46538497cf67fa01c89f: Deleting log segment in path: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566566673-30521-0/minicluster-data/ts-0-root/wals/6154aec59b6b4e2899d875f7e7a4407d/wal-000000018 (ops 86-90)
I20260812 06:19:35.673324 30856 log.cc:1079] T 6154aec59b6b4e2899d875f7e7a4407d P c8e8f4709f0d46538497cf67fa01c89f: Deleting log segment in path: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566566673-30521-0/minicluster-data/ts-0-root/wals/6154aec59b6b4e2899d875f7e7a4407d/wal-000000019 (ops 91-95)
I20260812 06:19:35.673367 30856 log.cc:1079] T 6154aec59b6b4e2899d875f7e7a4407d P c8e8f4709f0d46538497cf67fa01c89f: Deleting log segment in path: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566566673-30521-0/minicluster-data/ts-0-root/wals/6154aec59b6b4e2899d875f7e7a4407d/wal-000000020 (ops 96-100)
I20260812 06:19:35.673429 30856 log.cc:1079] T 6154aec59b6b4e2899d875f7e7a4407d P c8e8f4709f0d46538497cf67fa01c89f: Deleting log segment in path: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566566673-30521-0/minicluster-data/ts-0-root/wals/6154aec59b6b4e2899d875f7e7a4407d/wal-000000021 (ops 101-105)
I20260812 06:19:35.673470 30856 log.cc:1079] T 6154aec59b6b4e2899d875f7e7a4407d P c8e8f4709f0d46538497cf67fa01c89f: Deleting log segment in path: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566566673-30521-0/minicluster-data/ts-0-root/wals/6154aec59b6b4e2899d875f7e7a4407d/wal-000000022 (ops 106-110)
I20260812 06:19:35.673511 30856 log.cc:1079] T 6154aec59b6b4e2899d875f7e7a4407d P c8e8f4709f0d46538497cf67fa01c89f: Deleting log segment in path: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566566673-30521-0/minicluster-data/ts-0-root/wals/6154aec59b6b4e2899d875f7e7a4407d/wal-000000023 (ops 111-114)
I20260812 06:19:35.673550 30856 log.cc:1079] T 6154aec59b6b4e2899d875f7e7a4407d P c8e8f4709f0d46538497cf67fa01c89f: Deleting log segment in path: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566566673-30521-0/minicluster-data/ts-0-root/wals/6154aec59b6b4e2899d875f7e7a4407d/wal-000000024 (ops 115-119)
I20260812 06:19:35.673590 30856 log.cc:1079] T 6154aec59b6b4e2899d875f7e7a4407d P c8e8f4709f0d46538497cf67fa01c89f: Deleting log segment in path: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566566673-30521-0/minicluster-data/ts-0-root/wals/6154aec59b6b4e2899d875f7e7a4407d/wal-000000025 (ops 120-124)
I20260812 06:19:35.673629 30856 log.cc:1079] T 6154aec59b6b4e2899d875f7e7a4407d P c8e8f4709f0d46538497cf67fa01c89f: Deleting log segment in path: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566566673-30521-0/minicluster-data/ts-0-root/wals/6154aec59b6b4e2899d875f7e7a4407d/wal-000000026 (ops 125-128)
I20260812 06:19:35.673667 30856 log.cc:1079] T 6154aec59b6b4e2899d875f7e7a4407d P c8e8f4709f0d46538497cf67fa01c89f: Deleting log segment in path: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566566673-30521-0/minicluster-data/ts-0-root/wals/6154aec59b6b4e2899d875f7e7a4407d/wal-000000027 (ops 129-133)
I20260812 06:19:35.699965 30856 maintenance_manager.cc:643] P c8e8f4709f0d46538497cf67fa01c89f: LogGCOp(6154aec59b6b4e2899d875f7e7a4407d) complete. Timing: real 0.027s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:19:35.700379 30929 maintenance_manager.cc:419] P c8e8f4709f0d46538497cf67fa01c89f: Scheduling UndoDeltaBlockGCOp(6154aec59b6b4e2899d875f7e7a4407d): 493 bytes on disk
I20260812 06:19:35.700839 30856 maintenance_manager.cc:643] P c8e8f4709f0d46538497cf67fa01c89f: UndoDeltaBlockGCOp(6154aec59b6b4e2899d875f7e7a4407d) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":59,"lbm_reads_lt_1ms":4}
I20260812 06:19:35.701361 30929 maintenance_manager.cc:419] P c8e8f4709f0d46538497cf67fa01c89f: Scheduling FlushDeltaMemStoresOp(6154aec59b6b4e2899d875f7e7a4407d): perf score=6.157687
I20260812 06:19:35.727830 30856 maintenance_manager.cc:643] P c8e8f4709f0d46538497cf67fa01c89f: FlushDeltaMemStoresOp(6154aec59b6b4e2899d875f7e7a4407d) complete. Timing: real 0.026s	user 0.015s	sys 0.008s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":10463,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:19:35.728410 30929 maintenance_manager.cc:419] P c8e8f4709f0d46538497cf67fa01c89f: Scheduling MajorDeltaCompactionOp(6154aec59b6b4e2899d875f7e7a4407d): perf score=1.000000
I20260812 06:19:35.933117 30856 maintenance_manager.cc:643] P c8e8f4709f0d46538497cf67fa01c89f: MajorDeltaCompactionOp(6154aec59b6b4e2899d875f7e7a4407d) complete. Timing: real 0.205s	user 0.142s	sys 0.051s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877186,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":590,"lbm_read_time_us":12890,"lbm_reads_lt_1ms":665,"lbm_write_time_us":34879,"lbm_writes_lt_1ms":643,"mutex_wait_us":55,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":6400,"thread_start_us":81,"threads_started":1,"update_count":3000}
I20260812 06:19:35.933836 30929 maintenance_manager.cc:419] P c8e8f4709f0d46538497cf67fa01c89f: Scheduling FlushDeltaMemStoresOp(6154aec59b6b4e2899d875f7e7a4407d): perf score=18.063937
I20260812 06:19:35.992492 30856 maintenance_manager.cc:643] P c8e8f4709f0d46538497cf67fa01c89f: FlushDeltaMemStoresOp(6154aec59b6b4e2899d875f7e7a4407d) complete. Timing: real 0.058s	user 0.029s	sys 0.027s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":26350,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:35.993130 30929 maintenance_manager.cc:419] P c8e8f4709f0d46538497cf67fa01c89f: Scheduling FlushDeltaMemStoresOp(6154aec59b6b4e2899d875f7e7a4407d): perf score=2.188937
I20260812 06:19:36.006209 30856 maintenance_manager.cc:643] P c8e8f4709f0d46538497cf67fa01c89f: FlushDeltaMemStoresOp(6154aec59b6b4e2899d875f7e7a4407d) complete. Timing: real 0.013s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4473,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:36.006773 30929 maintenance_manager.cc:419] P c8e8f4709f0d46538497cf67fa01c89f: Scheduling MajorDeltaCompactionOp(6154aec59b6b4e2899d875f7e7a4407d): perf score=1.000000
I20260812 06:19:36.175313 30856 maintenance_manager.cc:643] P c8e8f4709f0d46538497cf67fa01c89f: MajorDeltaCompactionOp(6154aec59b6b4e2899d875f7e7a4407d) complete. Timing: real 0.168s	user 0.136s	sys 0.032s 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":258,"lbm_read_time_us":11154,"lbm_reads_lt_1ms":668,"lbm_write_time_us":34701,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":4224,"update_count":3000}
I20260812 06:19:36.175917 30929 maintenance_manager.cc:419] P c8e8f4709f0d46538497cf67fa01c89f: Scheduling FlushDeltaMemStoresOp(6154aec59b6b4e2899d875f7e7a4407d): perf score=14.095187
I20260812 06:19:36.225986 30856 maintenance_manager.cc:643] P c8e8f4709f0d46538497cf67fa01c89f: FlushDeltaMemStoresOp(6154aec59b6b4e2899d875f7e7a4407d) complete. Timing: real 0.050s	user 0.030s	sys 0.012s Metrics: {"bytes_written":16409899,"delete_count":0,"lbm_write_time_us":20262,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:36.226807 30929 maintenance_manager.cc:419] P c8e8f4709f0d46538497cf67fa01c89f: Scheduling FlushDeltaMemStoresOp(6154aec59b6b4e2899d875f7e7a4407d): perf score=2.188937
I20260812 06:19:36.239626 30856 maintenance_manager.cc:643] P c8e8f4709f0d46538497cf67fa01c89f: FlushDeltaMemStoresOp(6154aec59b6b4e2899d875f7e7a4407d) complete. Timing: real 0.013s	user 0.005s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4725,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:36.240159 30929 maintenance_manager.cc:419] P c8e8f4709f0d46538497cf67fa01c89f: Scheduling MajorDeltaCompactionOp(6154aec59b6b4e2899d875f7e7a4407d): perf score=1.000000
I20260812 06:19:36.404795 30856 maintenance_manager.cc:643] P c8e8f4709f0d46538497cf67fa01c89f: MajorDeltaCompactionOp(6154aec59b6b4e2899d875f7e7a4407d) complete. Timing: real 0.164s	user 0.120s	sys 0.041s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774686,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":885,"lbm_read_time_us":10831,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32019,"lbm_writes_lt_1ms":543,"mutex_wait_us":79,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6656,"update_count":2500}
I20260812 06:19:36.405562 30929 maintenance_manager.cc:419] P c8e8f4709f0d46538497cf67fa01c89f: Scheduling FlushDeltaMemStoresOp(6154aec59b6b4e2899d875f7e7a4407d): perf score=12.110812
I20260812 06:19:36.488920 30856 maintenance_manager.cc:643] P c8e8f4709f0d46538497cf67fa01c89f: FlushDeltaMemStoresOp(6154aec59b6b4e2899d875f7e7a4407d) complete. Timing: real 0.083s	user 0.024s	sys 0.023s Metrics: {"bytes_written":13825383,"delete_count":0,"lbm_write_time_us":51401,"lbm_writes_10-100_ms":1,"lbm_writes_lt_1ms":339,"reinsert_count":0,"update_count":1685}
I20260812 06:19:36.489490 30929 maintenance_manager.cc:419] P c8e8f4709f0d46538497cf67fa01c89f: Scheduling FlushDeltaMemStoresOp(6154aec59b6b4e2899d875f7e7a4407d): perf score=5.165500
I20260812 06:19:36.508379 30856 maintenance_manager.cc:643] P c8e8f4709f0d46538497cf67fa01c89f: FlushDeltaMemStoresOp(6154aec59b6b4e2899d875f7e7a4407d) complete. Timing: real 0.019s	user 0.009s	sys 0.008s Metrics: {"bytes_written":6687189,"delete_count":0,"lbm_write_time_us":7711,"lbm_writes_lt_1ms":166,"reinsert_count":0,"update_count":815}
I20260812 06:19:36.508919 30929 maintenance_manager.cc:419] P c8e8f4709f0d46538497cf67fa01c89f: Scheduling MajorDeltaCompactionOp(6154aec59b6b4e2899d875f7e7a4407d): perf score=1.000000
I20260812 06:19:36.682704 30856 maintenance_manager.cc:643] P c8e8f4709f0d46538497cf67fa01c89f: MajorDeltaCompactionOp(6154aec59b6b4e2899d875f7e7a4407d) complete. Timing: real 0.174s	user 0.125s	sys 0.046s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774694,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":215,"lbm_read_time_us":12460,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28863,"lbm_writes_lt_1ms":543,"mutex_wait_us":18,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":15104,"update_count":2500}
I20260812 06:19:36.683374 30929 maintenance_manager.cc:419] P c8e8f4709f0d46538497cf67fa01c89f: Scheduling FlushDeltaMemStoresOp(6154aec59b6b4e2899d875f7e7a4407d): perf score=14.095187
I20260812 06:19:36.742445 30856 maintenance_manager.cc:643] P c8e8f4709f0d46538497cf67fa01c89f: FlushDeltaMemStoresOp(6154aec59b6b4e2899d875f7e7a4407d) complete. Timing: real 0.056s	user 0.029s	sys 0.014s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20857,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:36.743108 30929 maintenance_manager.cc:419] P c8e8f4709f0d46538497cf67fa01c89f: Scheduling FlushDeltaMemStoresOp(6154aec59b6b4e2899d875f7e7a4407d): perf score=2.188937
I20260812 06:19:36.754220 30856 maintenance_manager.cc:643] P c8e8f4709f0d46538497cf67fa01c89f: FlushDeltaMemStoresOp(6154aec59b6b4e2899d875f7e7a4407d) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4065,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:36.755119 30929 maintenance_manager.cc:419] P c8e8f4709f0d46538497cf67fa01c89f: Scheduling MajorDeltaCompactionOp(6154aec59b6b4e2899d875f7e7a4407d): perf score=1.000000
I20260812 06:19:36.947434 30856 maintenance_manager.cc:643] P c8e8f4709f0d46538497cf67fa01c89f: MajorDeltaCompactionOp(6154aec59b6b4e2899d875f7e7a4407d) complete. Timing: real 0.192s	user 0.129s	sys 0.049s 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":118,"lbm_read_time_us":13181,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28993,"lbm_writes_lt_1ms":543,"mutex_wait_us":28,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11136,"update_count":2500}
I20260812 06:19:36.948304 30929 maintenance_manager.cc:419] P c8e8f4709f0d46538497cf67fa01c89f: Scheduling FlushDeltaMemStoresOp(6154aec59b6b4e2899d875f7e7a4407d): perf score=14.095187
I20260812 06:19:37.014412 30856 maintenance_manager.cc:643] P c8e8f4709f0d46538497cf67fa01c89f: FlushDeltaMemStoresOp(6154aec59b6b4e2899d875f7e7a4407d) complete. Timing: real 0.066s	user 0.030s	sys 0.026s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":27602,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"spinlock_wait_cycles":1920,"update_count":2000}
I20260812 06:19:37.015118 30929 maintenance_manager.cc:419] P c8e8f4709f0d46538497cf67fa01c89f: Scheduling FlushDeltaMemStoresOp(6154aec59b6b4e2899d875f7e7a4407d): perf score=2.188937
I20260812 06:19:37.026338 30856 maintenance_manager.cc:643] P c8e8f4709f0d46538497cf67fa01c89f: FlushDeltaMemStoresOp(6154aec59b6b4e2899d875f7e7a4407d) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4210,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:37.027045 30929 maintenance_manager.cc:419] P c8e8f4709f0d46538497cf67fa01c89f: Scheduling MajorDeltaCompactionOp(6154aec59b6b4e2899d875f7e7a4407d): perf score=1.000000
I20260812 06:19:37.225128 30856 maintenance_manager.cc:643] P c8e8f4709f0d46538497cf67fa01c89f: MajorDeltaCompactionOp(6154aec59b6b4e2899d875f7e7a4407d) complete. Timing: real 0.198s	user 0.148s	sys 0.040s 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":440,"lbm_read_time_us":15889,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29657,"lbm_writes_lt_1ms":543,"mutex_wait_us":97,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":25600,"update_count":2500}
I20260812 06:19:37.225845 30929 maintenance_manager.cc:419] P c8e8f4709f0d46538497cf67fa01c89f: Scheduling FlushDeltaMemStoresOp(6154aec59b6b4e2899d875f7e7a4407d): perf score=14.095187
I20260812 06:19:37.292994 30856 maintenance_manager.cc:643] P c8e8f4709f0d46538497cf67fa01c89f: FlushDeltaMemStoresOp(6154aec59b6b4e2899d875f7e7a4407d) complete. Timing: real 0.067s	user 0.031s	sys 0.027s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23653,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:37.293684 30929 maintenance_manager.cc:419] P c8e8f4709f0d46538497cf67fa01c89f: Scheduling FlushDeltaMemStoresOp(6154aec59b6b4e2899d875f7e7a4407d): perf score=2.188937
I20260812 06:19:37.304917 30856 maintenance_manager.cc:643] P c8e8f4709f0d46538497cf67fa01c89f: FlushDeltaMemStoresOp(6154aec59b6b4e2899d875f7e7a4407d) complete. Timing: real 0.011s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4386,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:37.305488 30929 maintenance_manager.cc:419] P c8e8f4709f0d46538497cf67fa01c89f: Scheduling FlushMRSOp(6154aec59b6b4e2899d875f7e7a4407d): perf score=1.000000
I20260812 06:19:37.349572 30856 maintenance_manager.cc:643] P c8e8f4709f0d46538497cf67fa01c89f: FlushMRSOp(6154aec59b6b4e2899d875f7e7a4407d) complete. Timing: real 0.044s	user 0.034s	sys 0.000s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":87,"dirs.run_cpu_time_us":250,"dirs.run_wall_time_us":1644,"drs_written":1,"lbm_read_time_us":40,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1593,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:19:37.350378 30929 maintenance_manager.cc:419] P c8e8f4709f0d46538497cf67fa01c89f: Scheduling LogGCOp(6154aec59b6b4e2899d875f7e7a4407d): free 128867786 bytes of WAL
I20260812 06:19:37.350673 30856 log_reader.cc:385] T 6154aec59b6b4e2899d875f7e7a4407d: removed 13 log segments from log reader
I20260812 06:19:37.350720 30856 log.cc:1079] T 6154aec59b6b4e2899d875f7e7a4407d P c8e8f4709f0d46538497cf67fa01c89f: Deleting log segment in path: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566566673-30521-0/minicluster-data/ts-0-root/wals/6154aec59b6b4e2899d875f7e7a4407d/wal-000000028 (ops 134-138)
I20260812 06:19:37.350750 30856 log.cc:1079] T 6154aec59b6b4e2899d875f7e7a4407d P c8e8f4709f0d46538497cf67fa01c89f: Deleting log segment in path: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566566673-30521-0/minicluster-data/ts-0-root/wals/6154aec59b6b4e2899d875f7e7a4407d/wal-000000029 (ops 139-142)
I20260812 06:19:37.350802 30856 log.cc:1079] T 6154aec59b6b4e2899d875f7e7a4407d P c8e8f4709f0d46538497cf67fa01c89f: Deleting log segment in path: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566566673-30521-0/minicluster-data/ts-0-root/wals/6154aec59b6b4e2899d875f7e7a4407d/wal-000000030 (ops 143-147)
I20260812 06:19:37.350848 30856 log.cc:1079] T 6154aec59b6b4e2899d875f7e7a4407d P c8e8f4709f0d46538497cf67fa01c89f: Deleting log segment in path: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566566673-30521-0/minicluster-data/ts-0-root/wals/6154aec59b6b4e2899d875f7e7a4407d/wal-000000031 (ops 148-152)
I20260812 06:19:37.350893 30856 log.cc:1079] T 6154aec59b6b4e2899d875f7e7a4407d P c8e8f4709f0d46538497cf67fa01c89f: Deleting log segment in path: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566566673-30521-0/minicluster-data/ts-0-root/wals/6154aec59b6b4e2899d875f7e7a4407d/wal-000000032 (ops 153-157)
I20260812 06:19:37.350934 30856 log.cc:1079] T 6154aec59b6b4e2899d875f7e7a4407d P c8e8f4709f0d46538497cf67fa01c89f: Deleting log segment in path: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566566673-30521-0/minicluster-data/ts-0-root/wals/6154aec59b6b4e2899d875f7e7a4407d/wal-000000033 (ops 158-162)
I20260812 06:19:37.350982 30856 log.cc:1079] T 6154aec59b6b4e2899d875f7e7a4407d P c8e8f4709f0d46538497cf67fa01c89f: Deleting log segment in path: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566566673-30521-0/minicluster-data/ts-0-root/wals/6154aec59b6b4e2899d875f7e7a4407d/wal-000000034 (ops 163-166)
I20260812 06:19:37.351063 30856 log.cc:1079] T 6154aec59b6b4e2899d875f7e7a4407d P c8e8f4709f0d46538497cf67fa01c89f: Deleting log segment in path: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566566673-30521-0/minicluster-data/ts-0-root/wals/6154aec59b6b4e2899d875f7e7a4407d/wal-000000035 (ops 167-171)
I20260812 06:19:37.351082 30856 log.cc:1079] T 6154aec59b6b4e2899d875f7e7a4407d P c8e8f4709f0d46538497cf67fa01c89f: Deleting log segment in path: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566566673-30521-0/minicluster-data/ts-0-root/wals/6154aec59b6b4e2899d875f7e7a4407d/wal-000000036 (ops 172-176)
I20260812 06:19:37.351132 30856 log.cc:1079] T 6154aec59b6b4e2899d875f7e7a4407d P c8e8f4709f0d46538497cf67fa01c89f: Deleting log segment in path: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566566673-30521-0/minicluster-data/ts-0-root/wals/6154aec59b6b4e2899d875f7e7a4407d/wal-000000037 (ops 177-180)
I20260812 06:19:37.351176 30856 log.cc:1079] T 6154aec59b6b4e2899d875f7e7a4407d P c8e8f4709f0d46538497cf67fa01c89f: Deleting log segment in path: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566566673-30521-0/minicluster-data/ts-0-root/wals/6154aec59b6b4e2899d875f7e7a4407d/wal-000000038 (ops 181-185)
I20260812 06:19:37.351214 30856 log.cc:1079] T 6154aec59b6b4e2899d875f7e7a4407d P c8e8f4709f0d46538497cf67fa01c89f: Deleting log segment in path: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566566673-30521-0/minicluster-data/ts-0-root/wals/6154aec59b6b4e2899d875f7e7a4407d/wal-000000039 (ops 186-190)
I20260812 06:19:37.351253 30856 log.cc:1079] T 6154aec59b6b4e2899d875f7e7a4407d P c8e8f4709f0d46538497cf67fa01c89f: Deleting log segment in path: /tmp/dist-test-taskCPXsea/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515566566673-30521-0/minicluster-data/ts-0-root/wals/6154aec59b6b4e2899d875f7e7a4407d/wal-000000040 (ops 191-195)
I20260812 06:19:37.380309 30856 maintenance_manager.cc:643] P c8e8f4709f0d46538497cf67fa01c89f: LogGCOp(6154aec59b6b4e2899d875f7e7a4407d) complete. Timing: real 0.030s	user 0.000s	sys 0.028s Metrics: {}
I20260812 06:19:37.380875 30929 maintenance_manager.cc:419] P c8e8f4709f0d46538497cf67fa01c89f: Scheduling FlushDeltaMemStoresOp(6154aec59b6b4e2899d875f7e7a4407d): perf score=3.181125
I20260812 06:19:37.397855 30521 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.924s	user 1.831s	sys 0.108s
I20260812 06:19:37.399621 30856 maintenance_manager.cc:643] P c8e8f4709f0d46538497cf67fa01c89f: FlushDeltaMemStoresOp(6154aec59b6b4e2899d875f7e7a4407d) complete. Timing: real 0.019s	user 0.003s	sys 0.009s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4803,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:37.400151 30929 maintenance_manager.cc:419] P c8e8f4709f0d46538497cf67fa01c89f: Scheduling UndoDeltaBlockGCOp(6154aec59b6b4e2899d875f7e7a4407d): 491 bytes on disk
I20260812 06:19:37.400784 30856 maintenance_manager.cc:643] P c8e8f4709f0d46538497cf67fa01c89f: UndoDeltaBlockGCOp(6154aec59b6b4e2899d875f7e7a4407d) 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:19:37.401473 30929 maintenance_manager.cc:419] P c8e8f4709f0d46538497cf67fa01c89f: Scheduling FlushDeltaMemStoresOp(6154aec59b6b4e2899d875f7e7a4407d): perf score=2.188937
I20260812 06:19:37.411381 30856 maintenance_manager.cc:643] P c8e8f4709f0d46538497cf67fa01c89f: FlushDeltaMemStoresOp(6154aec59b6b4e2899d875f7e7a4407d) complete. Timing: real 0.010s	user 0.008s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3693,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:37.411861 30929 maintenance_manager.cc:419] P c8e8f4709f0d46538497cf67fa01c89f: Scheduling MajorDeltaCompactionOp(6154aec59b6b4e2899d875f7e7a4407d): perf score=1.000000
I20260812 06:19:37.490731 30521 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.092s	user 0.004s	sys 0.000s
I20260812 06:19:37.491379 30521 tablet_server.cc:179] TabletServer@127.29.206.65:0 shutting down...
I20260812 06:19:37.585842 30856 maintenance_manager.cc:643] P c8e8f4709f0d46538497cf67fa01c89f: MajorDeltaCompactionOp(6154aec59b6b4e2899d875f7e7a4407d) complete. Timing: real 0.174s	user 0.114s	sys 0.060s Metrics: {"cfile_cache_hit":234,"cfile_cache_hit_bytes":9481901,"cfile_cache_miss":500,"cfile_cache_miss_bytes":23497836,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":722,"lbm_read_time_us":10549,"lbm_reads_lt_1ms":532,"lbm_write_time_us":34280,"lbm_writes_lt_1ms":743,"mutex_wait_us":67,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":10368,"thread_start_us":85,"threads_started":1,"update_count":3500}
I20260812 06:19:37.586575 30521 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:37.586951 30521 tablet_replica.cc:333] T 6154aec59b6b4e2899d875f7e7a4407d P c8e8f4709f0d46538497cf67fa01c89f: stopping tablet replica
I20260812 06:19:37.587270 30521 raft_consensus.cc:2243] T 6154aec59b6b4e2899d875f7e7a4407d P c8e8f4709f0d46538497cf67fa01c89f [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:37.587519 30521 raft_consensus.cc:2272] T 6154aec59b6b4e2899d875f7e7a4407d P c8e8f4709f0d46538497cf67fa01c89f [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:37.592885 30521 tablet_server.cc:196] TabletServer@127.29.206.65:0 shutdown complete.
I20260812 06:19:37.643622 30521 master.cc:562] Master@127.29.206.126:36223 shutting down...
I20260812 06:19:37.647790 30521 raft_consensus.cc:2243] T 00000000000000000000000000000000 P a822dcc8dab14e098dc5826830e416ff [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:37.648027 30521 raft_consensus.cc:2272] T 00000000000000000000000000000000 P a822dcc8dab14e098dc5826830e416ff [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:37.648123 30521 tablet_replica.cc:333] T 00000000000000000000000000000000 P a822dcc8dab14e098dc5826830e416ff: stopping tablet replica
I20260812 06:19:37.660724 30521 master.cc:584] Master@127.29.206.126:36223 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5485 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11173 ms total)

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