[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:17:45.368602 22570 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.22.10.190:35373
I20260812 06:17:45.369726 22570 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:17:45.370407 22570 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:45.377815 22580 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:17:45.377887 22570 server_base.cc:1061] running on GCE node
W20260812 06:17:45.377833 22577 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:45.378216 22578 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:45.378782 22570 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:45.378911 22570 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:45.378961 22570 hybrid_clock.cc:648] HybridClock initialized: now 1786515465378959 us; error 0 us; skew 500 ppm
I20260812 06:17:45.381047 22570 webserver.cc:533] Webserver started at http://127.22.10.190:42193/ using document root <none> and password file <none>
I20260812 06:17:45.381652 22570 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:45.381739 22570 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:45.382019 22570 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:45.383735 22570 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465356257-22570-0/minicluster-data/master-0-root/instance:
uuid: "898352f0a292406e8f656d5c1cd2c099"
format_stamp: "Formatted at 2026-08-12 06:17:45 on dist-test-slave-1zqn"
I20260812 06:17:45.387471 22570 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:17:45.390667 22586 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:45.392023 22570 fs_manager.cc:730] Time spent opening block manager: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:17:45.392199 22570 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465356257-22570-0/minicluster-data/master-0-root
uuid: "898352f0a292406e8f656d5c1cd2c099"
format_stamp: "Formatted at 2026-08-12 06:17:45 on dist-test-slave-1zqn"
I20260812 06:17:45.392314 22570 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465356257-22570-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465356257-22570-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465356257-22570-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:45.425745 22570 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:45.426484 22570 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:17:45.426698 22570 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:45.434737 22570 rpc_server.cc:307] RPC server started. Bound to: 127.22.10.190:35373
I20260812 06:17:45.434772 22646 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.22.10.190:35373 every 8 connection(s)
I20260812 06:17:45.437201 22647 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:45.442836 22647 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 898352f0a292406e8f656d5c1cd2c099: Bootstrap starting.
I20260812 06:17:45.445461 22647 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 898352f0a292406e8f656d5c1cd2c099: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:45.446523 22647 log.cc:826] T 00000000000000000000000000000000 P 898352f0a292406e8f656d5c1cd2c099: Log is configured to *not* fsync() on all Append() calls
I20260812 06:17:45.448473 22647 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 898352f0a292406e8f656d5c1cd2c099: No bootstrap required, opened a new log
I20260812 06:17:45.451552 22647 raft_consensus.cc:359] T 00000000000000000000000000000000 P 898352f0a292406e8f656d5c1cd2c099 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "898352f0a292406e8f656d5c1cd2c099" member_type: VOTER }
I20260812 06:17:45.451758 22647 raft_consensus.cc:385] T 00000000000000000000000000000000 P 898352f0a292406e8f656d5c1cd2c099 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:45.451848 22647 raft_consensus.cc:740] T 00000000000000000000000000000000 P 898352f0a292406e8f656d5c1cd2c099 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 898352f0a292406e8f656d5c1cd2c099, State: Initialized, Role: FOLLOWER
I20260812 06:17:45.452633 22647 consensus_queue.cc:260] T 00000000000000000000000000000000 P 898352f0a292406e8f656d5c1cd2c099 [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: "898352f0a292406e8f656d5c1cd2c099" member_type: VOTER }
I20260812 06:17:45.452824 22647 raft_consensus.cc:399] T 00000000000000000000000000000000 P 898352f0a292406e8f656d5c1cd2c099 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:45.452934 22647 raft_consensus.cc:493] T 00000000000000000000000000000000 P 898352f0a292406e8f656d5c1cd2c099 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:45.453085 22647 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 898352f0a292406e8f656d5c1cd2c099 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:45.454058 22647 raft_consensus.cc:515] T 00000000000000000000000000000000 P 898352f0a292406e8f656d5c1cd2c099 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "898352f0a292406e8f656d5c1cd2c099" member_type: VOTER }
I20260812 06:17:45.454608 22647 leader_election.cc:304] T 00000000000000000000000000000000 P 898352f0a292406e8f656d5c1cd2c099 [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: 898352f0a292406e8f656d5c1cd2c099; no voters: 
I20260812 06:17:45.455021 22647 leader_election.cc:290] T 00000000000000000000000000000000 P 898352f0a292406e8f656d5c1cd2c099 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:45.455190 22650 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 898352f0a292406e8f656d5c1cd2c099 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:45.455476 22650 raft_consensus.cc:697] T 00000000000000000000000000000000 P 898352f0a292406e8f656d5c1cd2c099 [term 1 LEADER]: Becoming Leader. State: Replica: 898352f0a292406e8f656d5c1cd2c099, State: Running, Role: LEADER
I20260812 06:17:45.456001 22650 consensus_queue.cc:237] T 00000000000000000000000000000000 P 898352f0a292406e8f656d5c1cd2c099 [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: "898352f0a292406e8f656d5c1cd2c099" member_type: VOTER }
I20260812 06:17:45.456329 22647 sys_catalog.cc:565] T 00000000000000000000000000000000 P 898352f0a292406e8f656d5c1cd2c099 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:45.458352 22651 sys_catalog.cc:455] T 00000000000000000000000000000000 P 898352f0a292406e8f656d5c1cd2c099 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "898352f0a292406e8f656d5c1cd2c099" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "898352f0a292406e8f656d5c1cd2c099" member_type: VOTER } }
I20260812 06:17:45.458339 22653 sys_catalog.cc:455] T 00000000000000000000000000000000 P 898352f0a292406e8f656d5c1cd2c099 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 898352f0a292406e8f656d5c1cd2c099. Latest consensus state: current_term: 1 leader_uuid: "898352f0a292406e8f656d5c1cd2c099" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "898352f0a292406e8f656d5c1cd2c099" member_type: VOTER } }
I20260812 06:17:45.458488 22651 sys_catalog.cc:458] T 00000000000000000000000000000000 P 898352f0a292406e8f656d5c1cd2c099 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:45.458545 22653 sys_catalog.cc:458] T 00000000000000000000000000000000 P 898352f0a292406e8f656d5c1cd2c099 [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:45.459095 22570 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
W20260812 06:17:45.461221 22675 catalog_manager.cc:1594] T 00000000000000000000000000000000 P 898352f0a292406e8f656d5c1cd2c099: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:17:45.461294 22675 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:17:45.461375 22674 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:45.462127 22674 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:45.467227 22674 catalog_manager.cc:1383] Generated new cluster ID: 30e733ec8a7742438cb6cafcd4c73c1e
I20260812 06:17:45.467309 22674 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:45.486580 22674 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:45.487854 22674 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:45.495219 22674 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 898352f0a292406e8f656d5c1cd2c099: Generated new TSK 0
I20260812 06:17:45.496001 22674 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:45.524212 22570 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:45.527163 22679 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:45.527316 22685 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:45.527326 22681 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:45.527464 22570 server_base.cc:1061] running on GCE node
I20260812 06:17:45.527793 22570 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:45.527848 22570 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:45.527871 22570 hybrid_clock.cc:648] HybridClock initialized: now 1786515465527871 us; error 0 us; skew 500 ppm
I20260812 06:17:45.528862 22570 webserver.cc:533] Webserver started at http://127.22.10.129:39179/ using document root <none> and password file <none>
I20260812 06:17:45.529040 22570 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:45.529102 22570 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:45.529173 22570 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:45.529629 22570 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465356257-22570-0/minicluster-data/ts-0-root/instance:
uuid: "842c220c1c944c669beef46d2626e1fd"
format_stamp: "Formatted at 2026-08-12 06:17:45 on dist-test-slave-1zqn"
I20260812 06:17:45.531502 22570 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:17:45.532656 22691 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:45.532931 22570 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.000s
I20260812 06:17:45.532996 22570 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465356257-22570-0/minicluster-data/ts-0-root
uuid: "842c220c1c944c669beef46d2626e1fd"
format_stamp: "Formatted at 2026-08-12 06:17:45 on dist-test-slave-1zqn"
I20260812 06:17:45.533087 22570 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465356257-22570-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465356257-22570-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465356257-22570-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:45.551386 22570 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:45.551960 22570 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:45.552583 22570 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:45.553516 22570 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:45.553571 22570 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:45.553648 22570 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:45.553690 22570 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:45.561319 22570 rpc_server.cc:307] RPC server started. Bound to: 127.22.10.129:46193
I20260812 06:17:45.561386 22770 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.22.10.129:46193 every 8 connection(s)
I20260812 06:17:45.575094 22772 heartbeater.cc:344] Connected to a master server at 127.22.10.190:35373
I20260812 06:17:45.575382 22772 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:45.575918 22772 heartbeater.cc:507] Master 127.22.10.190:35373 requested a full tablet report, sending...
I20260812 06:17:45.577436 22605 ts_manager.cc:194] Registered new tserver with Master: 842c220c1c944c669beef46d2626e1fd (127.22.10.129:46193)
I20260812 06:17:45.577862 22570 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.015815145s
I20260812 06:17:45.578933 22605 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:58718
I20260812 06:17:45.587651 22605 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:58724:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:17:45.602499 22728 tablet_service.cc:1511] Processing CreateTablet for tablet b69cec62913e474d8ffa850069e20034 (DEFAULT_TABLE table=heavy-update-compaction-test [id=7ff80c98116a4c0f8c2c4c43efbe834d]), partition=
I20260812 06:17:45.602982 22728 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet b69cec62913e474d8ffa850069e20034. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:45.605844 22788 tablet_bootstrap.cc:492] T b69cec62913e474d8ffa850069e20034 P 842c220c1c944c669beef46d2626e1fd: Bootstrap starting.
I20260812 06:17:45.606895 22788 tablet_bootstrap.cc:654] T b69cec62913e474d8ffa850069e20034 P 842c220c1c944c669beef46d2626e1fd: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:45.608908 22788 tablet_bootstrap.cc:492] T b69cec62913e474d8ffa850069e20034 P 842c220c1c944c669beef46d2626e1fd: No bootstrap required, opened a new log
I20260812 06:17:45.609082 22788 ts_tablet_manager.cc:1403] T b69cec62913e474d8ffa850069e20034 P 842c220c1c944c669beef46d2626e1fd: Time spent bootstrapping tablet: real 0.003s	user 0.000s	sys 0.002s
I20260812 06:17:45.609640 22788 raft_consensus.cc:359] T b69cec62913e474d8ffa850069e20034 P 842c220c1c944c669beef46d2626e1fd [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "842c220c1c944c669beef46d2626e1fd" member_type: VOTER last_known_addr { host: "127.22.10.129" port: 46193 } }
I20260812 06:17:45.609777 22788 raft_consensus.cc:385] T b69cec62913e474d8ffa850069e20034 P 842c220c1c944c669beef46d2626e1fd [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:45.609826 22788 raft_consensus.cc:740] T b69cec62913e474d8ffa850069e20034 P 842c220c1c944c669beef46d2626e1fd [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 842c220c1c944c669beef46d2626e1fd, State: Initialized, Role: FOLLOWER
I20260812 06:17:45.610070 22788 consensus_queue.cc:260] T b69cec62913e474d8ffa850069e20034 P 842c220c1c944c669beef46d2626e1fd [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: "842c220c1c944c669beef46d2626e1fd" member_type: VOTER last_known_addr { host: "127.22.10.129" port: 46193 } }
I20260812 06:17:45.610185 22788 raft_consensus.cc:399] T b69cec62913e474d8ffa850069e20034 P 842c220c1c944c669beef46d2626e1fd [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:45.610235 22788 raft_consensus.cc:493] T b69cec62913e474d8ffa850069e20034 P 842c220c1c944c669beef46d2626e1fd [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:45.610291 22788 raft_consensus.cc:3060] T b69cec62913e474d8ffa850069e20034 P 842c220c1c944c669beef46d2626e1fd [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:45.611189 22788 raft_consensus.cc:515] T b69cec62913e474d8ffa850069e20034 P 842c220c1c944c669beef46d2626e1fd [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "842c220c1c944c669beef46d2626e1fd" member_type: VOTER last_known_addr { host: "127.22.10.129" port: 46193 } }
I20260812 06:17:45.611380 22788 leader_election.cc:304] T b69cec62913e474d8ffa850069e20034 P 842c220c1c944c669beef46d2626e1fd [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: 842c220c1c944c669beef46d2626e1fd; no voters: 
I20260812 06:17:45.611635 22788 leader_election.cc:290] T b69cec62913e474d8ffa850069e20034 P 842c220c1c944c669beef46d2626e1fd [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:45.611977 22792 raft_consensus.cc:2804] T b69cec62913e474d8ffa850069e20034 P 842c220c1c944c669beef46d2626e1fd [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:45.612128 22788 ts_tablet_manager.cc:1434] T b69cec62913e474d8ffa850069e20034 P 842c220c1c944c669beef46d2626e1fd: Time spent starting tablet: real 0.003s	user 0.000s	sys 0.003s
I20260812 06:17:45.612293 22792 raft_consensus.cc:697] T b69cec62913e474d8ffa850069e20034 P 842c220c1c944c669beef46d2626e1fd [term 1 LEADER]: Becoming Leader. State: Replica: 842c220c1c944c669beef46d2626e1fd, State: Running, Role: LEADER
I20260812 06:17:45.612491 22792 consensus_queue.cc:237] T b69cec62913e474d8ffa850069e20034 P 842c220c1c944c669beef46d2626e1fd [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: "842c220c1c944c669beef46d2626e1fd" member_type: VOTER last_known_addr { host: "127.22.10.129" port: 46193 } }
I20260812 06:17:45.612584 22772 heartbeater.cc:499] Master 127.22.10.190:35373 was elected leader, sending a full tablet report...
I20260812 06:17:45.615609 22605 catalog_manager.cc:5719] T b69cec62913e474d8ffa850069e20034 P 842c220c1c944c669beef46d2626e1fd reported cstate change: term changed from 0 to 1, leader changed from <none> to 842c220c1c944c669beef46d2626e1fd (127.22.10.129). New cstate: current_term: 1 leader_uuid: "842c220c1c944c669beef46d2626e1fd" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "842c220c1c944c669beef46d2626e1fd" member_type: VOTER last_known_addr { host: "127.22.10.129" port: 46193 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:45.698418 22570 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.073s	user 0.017s	sys 0.012s
I20260812 06:17:45.812539 22774 maintenance_manager.cc:419] P 842c220c1c944c669beef46d2626e1fd: Scheduling FlushMRSOp(b69cec62913e474d8ffa850069e20034): perf score=10.125253
I20260812 06:17:45.971915 22699 maintenance_manager.cc:643] P 842c220c1c944c669beef46d2626e1fd: FlushMRSOp(b69cec62913e474d8ffa850069e20034) complete. Timing: real 0.159s	user 0.139s	sys 0.016s Metrics: {"bytes_written":12307490,"cfile_init":1,"compiler_manager_pool.queue_time_us":291,"delete_count":0,"dirs.queue_time_us":523,"dirs.run_cpu_time_us":226,"dirs.run_wall_time_us":977,"drs_written":1,"lbm_read_time_us":69,"lbm_reads_lt_1ms":4,"lbm_write_time_us":44142,"lbm_writes_lt_1ms":557,"peak_mem_usage":0,"reinsert_count":0,"rows_written":102,"spinlock_wait_cycles":1792,"thread_start_us":190,"threads_started":1,"update_count":1500}
I20260812 06:17:45.973251 22774 maintenance_manager.cc:419] P 842c220c1c944c669beef46d2626e1fd: Scheduling LogGCOp(b69cec62913e474d8ffa850069e20034): free 11976772 bytes of WAL
I20260812 06:17:45.973574 22699 log_reader.cc:385] T b69cec62913e474d8ffa850069e20034: removed 1 log segments from log reader
I20260812 06:17:45.973636 22699 log.cc:1079] T b69cec62913e474d8ffa850069e20034 P 842c220c1c944c669beef46d2626e1fd: Deleting log segment in path: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465356257-22570-0/minicluster-data/ts-0-root/wals/b69cec62913e474d8ffa850069e20034/wal-000000001 (ops 1-6)
I20260812 06:17:45.977205 22699 maintenance_manager.cc:643] P 842c220c1c944c669beef46d2626e1fd: LogGCOp(b69cec62913e474d8ffa850069e20034) complete. Timing: real 0.004s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:17:45.977631 22774 maintenance_manager.cc:419] P 842c220c1c944c669beef46d2626e1fd: Scheduling UndoDeltaBlockGCOp(b69cec62913e474d8ffa850069e20034): 8206537 bytes on disk
I20260812 06:17:45.978281 22699 maintenance_manager.cc:643] P 842c220c1c944c669beef46d2626e1fd: UndoDeltaBlockGCOp(b69cec62913e474d8ffa850069e20034) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":80,"lbm_reads_lt_1ms":4}
I20260812 06:17:45.978729 22774 maintenance_manager.cc:419] P 842c220c1c944c669beef46d2626e1fd: Scheduling FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034): perf score=2.188937
I20260812 06:17:45.996086 22699 maintenance_manager.cc:643] P 842c220c1c944c669beef46d2626e1fd: FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034) complete. Timing: real 0.017s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5707,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:45.996652 22774 maintenance_manager.cc:419] P 842c220c1c944c669beef46d2626e1fd: Scheduling MajorDeltaCompactionOp(b69cec62913e474d8ffa850069e20034): perf score=1.000000
I20260812 06:17:46.139894 22699 maintenance_manager.cc:643] P 842c220c1c944c669beef46d2626e1fd: MajorDeltaCompactionOp(b69cec62913e474d8ffa850069e20034) complete. Timing: real 0.143s	user 0.097s	sys 0.045s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590347,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":728,"lbm_read_time_us":8472,"lbm_reads_lt_1ms":460,"lbm_write_time_us":32282,"lbm_writes_lt_1ms":443,"mutex_wait_us":53,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1280,"thread_start_us":453,"threads_started":5,"update_count":2000}
I20260812 06:17:46.140501 22774 maintenance_manager.cc:419] P 842c220c1c944c669beef46d2626e1fd: Scheduling FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034): perf score=10.126437
I20260812 06:17:46.177181 22699 maintenance_manager.cc:643] P 842c220c1c944c669beef46d2626e1fd: FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034) complete. Timing: real 0.036s	user 0.020s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17669,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:46.177639 22774 maintenance_manager.cc:419] P 842c220c1c944c669beef46d2626e1fd: Scheduling FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034): perf score=2.188937
I20260812 06:17:46.188947 22699 maintenance_manager.cc:643] P 842c220c1c944c669beef46d2626e1fd: FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034) complete. Timing: real 0.011s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4288,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:46.189452 22774 maintenance_manager.cc:419] P 842c220c1c944c669beef46d2626e1fd: Scheduling MajorDeltaCompactionOp(b69cec62913e474d8ffa850069e20034): perf score=1.000000
I20260812 06:17:46.322559 22699 maintenance_manager.cc:643] P 842c220c1c944c669beef46d2626e1fd: MajorDeltaCompactionOp(b69cec62913e474d8ffa850069e20034) complete. Timing: real 0.133s	user 0.102s	sys 0.030s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590346,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":824,"lbm_read_time_us":8934,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26487,"lbm_writes_lt_1ms":443,"mutex_wait_us":393,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3840,"update_count":2000}
I20260812 06:17:46.323144 22774 maintenance_manager.cc:419] P 842c220c1c944c669beef46d2626e1fd: Scheduling FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034): perf score=10.126437
I20260812 06:17:46.377696 22699 maintenance_manager.cc:643] P 842c220c1c944c669beef46d2626e1fd: FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034) complete. Timing: real 0.054s	user 0.023s	sys 0.023s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":16905,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:46.378253 22774 maintenance_manager.cc:419] P 842c220c1c944c669beef46d2626e1fd: Scheduling FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034): perf score=2.188937
I20260812 06:17:46.389288 22699 maintenance_manager.cc:643] P 842c220c1c944c669beef46d2626e1fd: FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4339,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:46.389724 22774 maintenance_manager.cc:419] P 842c220c1c944c669beef46d2626e1fd: Scheduling MajorDeltaCompactionOp(b69cec62913e474d8ffa850069e20034): perf score=1.000000
I20260812 06:17:46.549705 22699 maintenance_manager.cc:643] P 842c220c1c944c669beef46d2626e1fd: MajorDeltaCompactionOp(b69cec62913e474d8ffa850069e20034) complete. Timing: real 0.160s	user 0.112s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590349,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":190,"lbm_read_time_us":12663,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24354,"lbm_writes_lt_1ms":443,"mutex_wait_us":52,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":14080,"update_count":2000}
I20260812 06:17:46.550298 22774 maintenance_manager.cc:419] P 842c220c1c944c669beef46d2626e1fd: Scheduling FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034): perf score=10.126437
I20260812 06:17:46.585819 22699 maintenance_manager.cc:643] P 842c220c1c944c669beef46d2626e1fd: FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034) complete. Timing: real 0.035s	user 0.022s	sys 0.008s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":13540,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:46.586387 22774 maintenance_manager.cc:419] P 842c220c1c944c669beef46d2626e1fd: Scheduling MajorDeltaCompactionOp(b69cec62913e474d8ffa850069e20034): perf score=1.000000
I20260812 06:17:46.702455 22699 maintenance_manager.cc:643] P 842c220c1c944c669beef46d2626e1fd: MajorDeltaCompactionOp(b69cec62913e474d8ffa850069e20034) complete. Timing: real 0.116s	user 0.090s	sys 0.024s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16487817,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":341,"lbm_read_time_us":6809,"lbm_reads_lt_1ms":363,"lbm_write_time_us":23421,"lbm_writes_lt_1ms":343,"mutex_wait_us":70,"peak_mem_usage":38262756,"reinsert_count":0,"update_count":1500}
I20260812 06:17:46.703091 22774 maintenance_manager.cc:419] P 842c220c1c944c669beef46d2626e1fd: Scheduling FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034): perf score=10.126437
I20260812 06:17:46.739008 22699 maintenance_manager.cc:643] P 842c220c1c944c669beef46d2626e1fd: FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034) complete. Timing: real 0.036s	user 0.021s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13490,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:46.739511 22774 maintenance_manager.cc:419] P 842c220c1c944c669beef46d2626e1fd: Scheduling MajorDeltaCompactionOp(b69cec62913e474d8ffa850069e20034): perf score=1.000000
I20260812 06:17:46.853088 22699 maintenance_manager.cc:643] P 842c220c1c944c669beef46d2626e1fd: MajorDeltaCompactionOp(b69cec62913e474d8ffa850069e20034) complete. Timing: real 0.113s	user 0.101s	sys 0.012s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16487816,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":769,"lbm_read_time_us":7595,"lbm_reads_lt_1ms":363,"lbm_write_time_us":20091,"lbm_writes_lt_1ms":343,"mutex_wait_us":360,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":81024,"update_count":1500}
I20260812 06:17:46.853742 22774 maintenance_manager.cc:419] P 842c220c1c944c669beef46d2626e1fd: Scheduling FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034): perf score=10.126437
I20260812 06:17:46.896253 22699 maintenance_manager.cc:643] P 842c220c1c944c669beef46d2626e1fd: FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034) complete. Timing: real 0.042s	user 0.025s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16007,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:46.896852 22774 maintenance_manager.cc:419] P 842c220c1c944c669beef46d2626e1fd: Scheduling FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034): perf score=2.188937
I20260812 06:17:46.908337 22699 maintenance_manager.cc:643] P 842c220c1c944c669beef46d2626e1fd: FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034) complete. Timing: real 0.011s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4257,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:46.909092 22774 maintenance_manager.cc:419] P 842c220c1c944c669beef46d2626e1fd: Scheduling MajorDeltaCompactionOp(b69cec62913e474d8ffa850069e20034): perf score=1.000000
I20260812 06:17:47.035182 22699 maintenance_manager.cc:643] P 842c220c1c944c669beef46d2626e1fd: MajorDeltaCompactionOp(b69cec62913e474d8ffa850069e20034) complete. Timing: real 0.126s	user 0.090s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590347,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":182,"lbm_read_time_us":9326,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22871,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:17:47.035753 22774 maintenance_manager.cc:419] P 842c220c1c944c669beef46d2626e1fd: Scheduling FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034): perf score=10.126437
I20260812 06:17:47.079085 22699 maintenance_manager.cc:643] P 842c220c1c944c669beef46d2626e1fd: FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034) complete. Timing: real 0.043s	user 0.019s	sys 0.021s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19652,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:17:47.079768 22774 maintenance_manager.cc:419] P 842c220c1c944c669beef46d2626e1fd: Scheduling FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034): perf score=2.188937
I20260812 06:17:47.097694 22699 maintenance_manager.cc:643] P 842c220c1c944c669beef46d2626e1fd: FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034) complete. Timing: real 0.018s	user 0.012s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6919,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:47.098224 22774 maintenance_manager.cc:419] P 842c220c1c944c669beef46d2626e1fd: Scheduling MajorDeltaCompactionOp(b69cec62913e474d8ffa850069e20034): perf score=1.000000
I20260812 06:17:47.224699 22699 maintenance_manager.cc:643] P 842c220c1c944c669beef46d2626e1fd: MajorDeltaCompactionOp(b69cec62913e474d8ffa850069e20034) complete. Timing: real 0.126s	user 0.094s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590347,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1071,"lbm_read_time_us":8422,"lbm_reads_lt_1ms":468,"lbm_write_time_us":24992,"lbm_writes_lt_1ms":443,"mutex_wait_us":289,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":10112,"update_count":2000}
I20260812 06:17:47.225574 22774 maintenance_manager.cc:419] P 842c220c1c944c669beef46d2626e1fd: Scheduling FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034): perf score=10.126437
I20260812 06:17:47.267380 22699 maintenance_manager.cc:643] P 842c220c1c944c669beef46d2626e1fd: FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034) complete. Timing: real 0.042s	user 0.023s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":19687,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:17:47.267911 22774 maintenance_manager.cc:419] P 842c220c1c944c669beef46d2626e1fd: Scheduling FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034): perf score=2.188937
I20260812 06:17:47.280407 22699 maintenance_manager.cc:643] P 842c220c1c944c669beef46d2626e1fd: FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034) complete. Timing: real 0.012s	user 0.009s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4157,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:47.280869 22774 maintenance_manager.cc:419] P 842c220c1c944c669beef46d2626e1fd: Scheduling FlushMRSOp(b69cec62913e474d8ffa850069e20034): perf score=1.000000
I20260812 06:17:47.311744 22699 maintenance_manager.cc:643] P 842c220c1c944c669beef46d2626e1fd: FlushMRSOp(b69cec62913e474d8ffa850069e20034) complete. Timing: real 0.031s	user 0.024s	sys 0.005s Metrics: {"bytes_written":1234474,"cfile_init":1,"dirs.queue_time_us":90,"dirs.run_cpu_time_us":300,"dirs.run_wall_time_us":1478,"drs_written":1,"lbm_read_time_us":68,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1393,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:17:47.312745 22774 maintenance_manager.cc:419] P 842c220c1c944c669beef46d2626e1fd: Scheduling LogGCOp(b69cec62913e474d8ffa850069e20034): free 121459483 bytes of WAL
I20260812 06:17:47.312990 22699 log_reader.cc:385] T b69cec62913e474d8ffa850069e20034: removed 12 log segments from log reader
I20260812 06:17:47.313035 22699 log.cc:1079] T b69cec62913e474d8ffa850069e20034 P 842c220c1c944c669beef46d2626e1fd: Deleting log segment in path: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465356257-22570-0/minicluster-data/ts-0-root/wals/b69cec62913e474d8ffa850069e20034/wal-000000002 (ops 7-11)
I20260812 06:17:47.313066 22699 log.cc:1079] T b69cec62913e474d8ffa850069e20034 P 842c220c1c944c669beef46d2626e1fd: Deleting log segment in path: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465356257-22570-0/minicluster-data/ts-0-root/wals/b69cec62913e474d8ffa850069e20034/wal-000000003 (ops 12-16)
I20260812 06:17:47.313133 22699 log.cc:1079] T b69cec62913e474d8ffa850069e20034 P 842c220c1c944c669beef46d2626e1fd: Deleting log segment in path: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465356257-22570-0/minicluster-data/ts-0-root/wals/b69cec62913e474d8ffa850069e20034/wal-000000004 (ops 17-21)
I20260812 06:17:47.313162 22699 log.cc:1079] T b69cec62913e474d8ffa850069e20034 P 842c220c1c944c669beef46d2626e1fd: Deleting log segment in path: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465356257-22570-0/minicluster-data/ts-0-root/wals/b69cec62913e474d8ffa850069e20034/wal-000000005 (ops 22-26)
I20260812 06:17:47.313201 22699 log.cc:1079] T b69cec62913e474d8ffa850069e20034 P 842c220c1c944c669beef46d2626e1fd: Deleting log segment in path: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465356257-22570-0/minicluster-data/ts-0-root/wals/b69cec62913e474d8ffa850069e20034/wal-000000006 (ops 27-31)
I20260812 06:17:47.313261 22699 log.cc:1079] T b69cec62913e474d8ffa850069e20034 P 842c220c1c944c669beef46d2626e1fd: Deleting log segment in path: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465356257-22570-0/minicluster-data/ts-0-root/wals/b69cec62913e474d8ffa850069e20034/wal-000000007 (ops 32-36)
I20260812 06:17:47.313299 22699 log.cc:1079] T b69cec62913e474d8ffa850069e20034 P 842c220c1c944c669beef46d2626e1fd: Deleting log segment in path: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465356257-22570-0/minicluster-data/ts-0-root/wals/b69cec62913e474d8ffa850069e20034/wal-000000008 (ops 37-41)
I20260812 06:17:47.313338 22699 log.cc:1079] T b69cec62913e474d8ffa850069e20034 P 842c220c1c944c669beef46d2626e1fd: Deleting log segment in path: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465356257-22570-0/minicluster-data/ts-0-root/wals/b69cec62913e474d8ffa850069e20034/wal-000000009 (ops 42-46)
I20260812 06:17:47.313376 22699 log.cc:1079] T b69cec62913e474d8ffa850069e20034 P 842c220c1c944c669beef46d2626e1fd: Deleting log segment in path: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465356257-22570-0/minicluster-data/ts-0-root/wals/b69cec62913e474d8ffa850069e20034/wal-000000010 (ops 47-51)
I20260812 06:17:47.313416 22699 log.cc:1079] T b69cec62913e474d8ffa850069e20034 P 842c220c1c944c669beef46d2626e1fd: Deleting log segment in path: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465356257-22570-0/minicluster-data/ts-0-root/wals/b69cec62913e474d8ffa850069e20034/wal-000000011 (ops 52-56)
I20260812 06:17:47.313457 22699 log.cc:1079] T b69cec62913e474d8ffa850069e20034 P 842c220c1c944c669beef46d2626e1fd: Deleting log segment in path: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465356257-22570-0/minicluster-data/ts-0-root/wals/b69cec62913e474d8ffa850069e20034/wal-000000012 (ops 57-61)
I20260812 06:17:47.313494 22699 log.cc:1079] T b69cec62913e474d8ffa850069e20034 P 842c220c1c944c669beef46d2626e1fd: Deleting log segment in path: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465356257-22570-0/minicluster-data/ts-0-root/wals/b69cec62913e474d8ffa850069e20034/wal-000000013 (ops 62-66)
I20260812 06:17:47.343511 22699 maintenance_manager.cc:643] P 842c220c1c944c669beef46d2626e1fd: LogGCOp(b69cec62913e474d8ffa850069e20034) complete. Timing: real 0.031s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:17:47.344053 22774 maintenance_manager.cc:419] P 842c220c1c944c669beef46d2626e1fd: Scheduling UndoDeltaBlockGCOp(b69cec62913e474d8ffa850069e20034): 472 bytes on disk
I20260812 06:17:47.344590 22699 maintenance_manager.cc:643] P 842c220c1c944c669beef46d2626e1fd: UndoDeltaBlockGCOp(b69cec62913e474d8ffa850069e20034) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4}
I20260812 06:17:47.345095 22774 maintenance_manager.cc:419] P 842c220c1c944c669beef46d2626e1fd: Scheduling FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034): perf score=3.181125
I20260812 06:17:47.357537 22699 maintenance_manager.cc:643] P 842c220c1c944c669beef46d2626e1fd: FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034) complete. Timing: real 0.012s	user 0.002s	sys 0.009s Metrics: {"bytes_written":4759050,"delete_count":0,"lbm_write_time_us":4986,"lbm_writes_lt_1ms":119,"reinsert_count":0,"update_count":580}
I20260812 06:17:47.358186 22774 maintenance_manager.cc:419] P 842c220c1c944c669beef46d2626e1fd: Scheduling FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034): perf score=2.188937
I20260812 06:17:47.367954 22699 maintenance_manager.cc:643] P 842c220c1c944c669beef46d2626e1fd: FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034) complete. Timing: real 0.010s	user 0.004s	sys 0.003s Metrics: {"bytes_written":3446255,"delete_count":0,"lbm_write_time_us":3488,"lbm_writes_lt_1ms":87,"reinsert_count":0,"update_count":420}
I20260812 06:17:47.369236 22774 maintenance_manager.cc:419] P 842c220c1c944c669beef46d2626e1fd: Scheduling MajorDeltaCompactionOp(b69cec62913e474d8ffa850069e20034): perf score=1.000000
I20260812 06:17:47.539939 22699 maintenance_manager.cc:643] P 842c220c1c944c669beef46d2626e1fd: MajorDeltaCompactionOp(b69cec62913e474d8ffa850069e20034) complete. Timing: real 0.170s	user 0.114s	sys 0.056s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28795396,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":615,"lbm_read_time_us":12225,"lbm_reads_lt_1ms":674,"lbm_write_time_us":35919,"lbm_writes_lt_1ms":643,"mutex_wait_us":332,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":10880,"thread_start_us":89,"threads_started":1,"update_count":3000}
I20260812 06:17:47.540777 22774 maintenance_manager.cc:419] P 842c220c1c944c669beef46d2626e1fd: Scheduling FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034): perf score=14.095187
I20260812 06:17:47.598397 22699 maintenance_manager.cc:643] P 842c220c1c944c669beef46d2626e1fd: FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034) complete. Timing: real 0.057s	user 0.033s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22427,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:47.598948 22774 maintenance_manager.cc:419] P 842c220c1c944c669beef46d2626e1fd: Scheduling FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034): perf score=2.188937
I20260812 06:17:47.610841 22699 maintenance_manager.cc:643] P 842c220c1c944c669beef46d2626e1fd: FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4154,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:47.611357 22774 maintenance_manager.cc:419] P 842c220c1c944c669beef46d2626e1fd: Scheduling MajorDeltaCompactionOp(b69cec62913e474d8ffa850069e20034): perf score=1.000000
I20260812 06:17:47.772827 22699 maintenance_manager.cc:643] P 842c220c1c944c669beef46d2626e1fd: MajorDeltaCompactionOp(b69cec62913e474d8ffa850069e20034) complete. Timing: real 0.161s	user 0.103s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24692758,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1175,"lbm_read_time_us":11482,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27996,"lbm_writes_lt_1ms":543,"mutex_wait_us":326,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":19712,"update_count":2500}
I20260812 06:17:47.773559 22774 maintenance_manager.cc:419] P 842c220c1c944c669beef46d2626e1fd: Scheduling FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034): perf score=14.095187
I20260812 06:17:47.827214 22699 maintenance_manager.cc:643] P 842c220c1c944c669beef46d2626e1fd: FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034) complete. Timing: real 0.053s	user 0.027s	sys 0.021s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21428,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:47.827768 22774 maintenance_manager.cc:419] P 842c220c1c944c669beef46d2626e1fd: Scheduling MajorDeltaCompactionOp(b69cec62913e474d8ffa850069e20034): perf score=1.000000
I20260812 06:17:47.975155 22699 maintenance_manager.cc:643] P 842c220c1c944c669beef46d2626e1fd: MajorDeltaCompactionOp(b69cec62913e474d8ffa850069e20034) complete. Timing: real 0.147s	user 0.093s	sys 0.048s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20590228,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":166,"lbm_read_time_us":9628,"lbm_reads_lt_1ms":463,"lbm_write_time_us":22737,"lbm_writes_lt_1ms":443,"mutex_wait_us":42,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3968,"update_count":2000}
I20260812 06:17:47.975812 22774 maintenance_manager.cc:419] P 842c220c1c944c669beef46d2626e1fd: Scheduling FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034): perf score=14.095187
I20260812 06:17:48.028950 22699 maintenance_manager.cc:643] P 842c220c1c944c669beef46d2626e1fd: FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034) complete. Timing: real 0.053s	user 0.037s	sys 0.015s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24122,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:48.029484 22774 maintenance_manager.cc:419] P 842c220c1c944c669beef46d2626e1fd: Scheduling FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034): perf score=2.188937
I20260812 06:17:48.055471 22699 maintenance_manager.cc:643] P 842c220c1c944c669beef46d2626e1fd: FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034) complete. Timing: real 0.026s	user 0.010s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6760,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:48.056382 22774 maintenance_manager.cc:419] P 842c220c1c944c669beef46d2626e1fd: Scheduling MajorDeltaCompactionOp(b69cec62913e474d8ffa850069e20034): perf score=1.000000
I20260812 06:17:48.261209 22699 maintenance_manager.cc:643] P 842c220c1c944c669beef46d2626e1fd: MajorDeltaCompactionOp(b69cec62913e474d8ffa850069e20034) complete. Timing: real 0.205s	user 0.139s	sys 0.064s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24692758,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":241,"lbm_read_time_us":14041,"lbm_reads_lt_1ms":564,"lbm_write_time_us":34705,"lbm_writes_lt_1ms":543,"mutex_wait_us":55,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:17:48.262050 22774 maintenance_manager.cc:419] P 842c220c1c944c669beef46d2626e1fd: Scheduling FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034): perf score=15.087375
I20260812 06:17:48.317457 22699 maintenance_manager.cc:643] P 842c220c1c944c669beef46d2626e1fd: FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034) complete. Timing: real 0.055s	user 0.042s	sys 0.011s Metrics: {"bytes_written":16820143,"delete_count":0,"lbm_write_time_us":23658,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:17:48.317989 22774 maintenance_manager.cc:419] P 842c220c1c944c669beef46d2626e1fd: Scheduling FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034): perf score=2.188937
I20260812 06:17:48.335580 22699 maintenance_manager.cc:643] P 842c220c1c944c669beef46d2626e1fd: FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034) complete. Timing: real 0.017s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4788,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:48.336164 22774 maintenance_manager.cc:419] P 842c220c1c944c669beef46d2626e1fd: Scheduling FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034): perf score=2.188937
I20260812 06:17:48.355744 22699 maintenance_manager.cc:643] P 842c220c1c944c669beef46d2626e1fd: FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034) complete. Timing: real 0.019s	user 0.008s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3661,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:48.356366 22774 maintenance_manager.cc:419] P 842c220c1c944c669beef46d2626e1fd: Scheduling MajorDeltaCompactionOp(b69cec62913e474d8ffa850069e20034): perf score=1.000000
I20260812 06:17:48.569528 22699 maintenance_manager.cc:643] P 842c220c1c944c669beef46d2626e1fd: MajorDeltaCompactionOp(b69cec62913e474d8ffa850069e20034) complete. Timing: real 0.213s	user 0.129s	sys 0.081s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28795277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":924,"lbm_read_time_us":15968,"lbm_reads_lt_1ms":673,"lbm_write_time_us":35628,"lbm_writes_lt_1ms":643,"mutex_wait_us":2,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":3840,"update_count":3000}
I20260812 06:17:48.570031 22774 maintenance_manager.cc:419] P 842c220c1c944c669beef46d2626e1fd: Scheduling FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034): perf score=14.095187
I20260812 06:17:48.619302 22699 maintenance_manager.cc:643] P 842c220c1c944c669beef46d2626e1fd: FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034) complete. Timing: real 0.049s	user 0.014s	sys 0.032s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21706,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:48.620150 22774 maintenance_manager.cc:419] P 842c220c1c944c669beef46d2626e1fd: Scheduling FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034): perf score=2.188937
I20260812 06:17:48.644379 22699 maintenance_manager.cc:643] P 842c220c1c944c669beef46d2626e1fd: FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034) complete. Timing: real 0.024s	user 0.016s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5469,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:48.644994 22774 maintenance_manager.cc:419] P 842c220c1c944c669beef46d2626e1fd: Scheduling MajorDeltaCompactionOp(b69cec62913e474d8ffa850069e20034): perf score=1.000000
I20260812 06:17:48.834309 22699 maintenance_manager.cc:643] P 842c220c1c944c669beef46d2626e1fd: MajorDeltaCompactionOp(b69cec62913e474d8ffa850069e20034) complete. Timing: real 0.189s	user 0.123s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24692758,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1110,"lbm_read_time_us":12469,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28850,"lbm_writes_lt_1ms":543,"mutex_wait_us":67,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":25088,"update_count":2500}
I20260812 06:17:48.835134 22774 maintenance_manager.cc:419] P 842c220c1c944c669beef46d2626e1fd: Scheduling FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034): perf score=14.095187
I20260812 06:17:48.885775 22699 maintenance_manager.cc:643] P 842c220c1c944c669beef46d2626e1fd: FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034) complete. Timing: real 0.050s	user 0.025s	sys 0.023s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22241,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:48.886343 22774 maintenance_manager.cc:419] P 842c220c1c944c669beef46d2626e1fd: Scheduling FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034): perf score=2.188937
I20260812 06:17:48.901068 22699 maintenance_manager.cc:643] P 842c220c1c944c669beef46d2626e1fd: FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034) complete. Timing: real 0.015s	user 0.008s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5545,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:48.902107 22774 maintenance_manager.cc:419] P 842c220c1c944c669beef46d2626e1fd: Scheduling FlushMRSOp(b69cec62913e474d8ffa850069e20034): perf score=1.000000
I20260812 06:17:48.943393 22699 maintenance_manager.cc:643] P 842c220c1c944c669beef46d2626e1fd: FlushMRSOp(b69cec62913e474d8ffa850069e20034) complete. Timing: real 0.041s	user 0.034s	sys 0.005s Metrics: {"bytes_written":1357580,"cfile_init":1,"dirs.queue_time_us":82,"dirs.run_cpu_time_us":192,"dirs.run_wall_time_us":1518,"drs_written":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2458,"lbm_writes_lt_1ms":44,"peak_mem_usage":0,"rows_written":33}
I20260812 06:17:48.944285 22774 maintenance_manager.cc:419] P 842c220c1c944c669beef46d2626e1fd: Scheduling LogGCOp(b69cec62913e474d8ffa850069e20034): free 132571319 bytes of WAL
I20260812 06:17:48.944579 22699 log_reader.cc:385] T b69cec62913e474d8ffa850069e20034: removed 13 log segments from log reader
I20260812 06:17:48.944648 22699 log.cc:1079] T b69cec62913e474d8ffa850069e20034 P 842c220c1c944c669beef46d2626e1fd: Deleting log segment in path: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465356257-22570-0/minicluster-data/ts-0-root/wals/b69cec62913e474d8ffa850069e20034/wal-000000014 (ops 67-70)
I20260812 06:17:48.944689 22699 log.cc:1079] T b69cec62913e474d8ffa850069e20034 P 842c220c1c944c669beef46d2626e1fd: Deleting log segment in path: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465356257-22570-0/minicluster-data/ts-0-root/wals/b69cec62913e474d8ffa850069e20034/wal-000000015 (ops 71-75)
I20260812 06:17:48.944722 22699 log.cc:1079] T b69cec62913e474d8ffa850069e20034 P 842c220c1c944c669beef46d2626e1fd: Deleting log segment in path: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465356257-22570-0/minicluster-data/ts-0-root/wals/b69cec62913e474d8ffa850069e20034/wal-000000016 (ops 76-80)
I20260812 06:17:48.944746 22699 log.cc:1079] T b69cec62913e474d8ffa850069e20034 P 842c220c1c944c669beef46d2626e1fd: Deleting log segment in path: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465356257-22570-0/minicluster-data/ts-0-root/wals/b69cec62913e474d8ffa850069e20034/wal-000000017 (ops 81-85)
I20260812 06:17:48.944772 22699 log.cc:1079] T b69cec62913e474d8ffa850069e20034 P 842c220c1c944c669beef46d2626e1fd: Deleting log segment in path: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465356257-22570-0/minicluster-data/ts-0-root/wals/b69cec62913e474d8ffa850069e20034/wal-000000018 (ops 86-90)
I20260812 06:17:48.944805 22699 log.cc:1079] T b69cec62913e474d8ffa850069e20034 P 842c220c1c944c669beef46d2626e1fd: Deleting log segment in path: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465356257-22570-0/minicluster-data/ts-0-root/wals/b69cec62913e474d8ffa850069e20034/wal-000000019 (ops 91-94)
I20260812 06:17:48.944836 22699 log.cc:1079] T b69cec62913e474d8ffa850069e20034 P 842c220c1c944c669beef46d2626e1fd: Deleting log segment in path: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465356257-22570-0/minicluster-data/ts-0-root/wals/b69cec62913e474d8ffa850069e20034/wal-000000020 (ops 95-99)
I20260812 06:17:48.944866 22699 log.cc:1079] T b69cec62913e474d8ffa850069e20034 P 842c220c1c944c669beef46d2626e1fd: Deleting log segment in path: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465356257-22570-0/minicluster-data/ts-0-root/wals/b69cec62913e474d8ffa850069e20034/wal-000000021 (ops 100-104)
I20260812 06:17:48.944895 22699 log.cc:1079] T b69cec62913e474d8ffa850069e20034 P 842c220c1c944c669beef46d2626e1fd: Deleting log segment in path: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465356257-22570-0/minicluster-data/ts-0-root/wals/b69cec62913e474d8ffa850069e20034/wal-000000022 (ops 105-109)
I20260812 06:17:48.944926 22699 log.cc:1079] T b69cec62913e474d8ffa850069e20034 P 842c220c1c944c669beef46d2626e1fd: Deleting log segment in path: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465356257-22570-0/minicluster-data/ts-0-root/wals/b69cec62913e474d8ffa850069e20034/wal-000000023 (ops 110-114)
I20260812 06:17:48.944962 22699 log.cc:1079] T b69cec62913e474d8ffa850069e20034 P 842c220c1c944c669beef46d2626e1fd: Deleting log segment in path: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465356257-22570-0/minicluster-data/ts-0-root/wals/b69cec62913e474d8ffa850069e20034/wal-000000024 (ops 115-119)
I20260812 06:17:48.944996 22699 log.cc:1079] T b69cec62913e474d8ffa850069e20034 P 842c220c1c944c669beef46d2626e1fd: Deleting log segment in path: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465356257-22570-0/minicluster-data/ts-0-root/wals/b69cec62913e474d8ffa850069e20034/wal-000000025 (ops 120-124)
I20260812 06:17:48.945026 22699 log.cc:1079] T b69cec62913e474d8ffa850069e20034 P 842c220c1c944c669beef46d2626e1fd: Deleting log segment in path: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465356257-22570-0/minicluster-data/ts-0-root/wals/b69cec62913e474d8ffa850069e20034/wal-000000026 (ops 125-129)
I20260812 06:17:48.979560 22699 maintenance_manager.cc:643] P 842c220c1c944c669beef46d2626e1fd: LogGCOp(b69cec62913e474d8ffa850069e20034) complete. Timing: real 0.035s	user 0.000s	sys 0.032s Metrics: {}
I20260812 06:17:48.980357 22774 maintenance_manager.cc:419] P 842c220c1c944c669beef46d2626e1fd: Scheduling UndoDeltaBlockGCOp(b69cec62913e474d8ffa850069e20034): 507 bytes on disk
I20260812 06:17:48.980898 22699 maintenance_manager.cc:643] P 842c220c1c944c669beef46d2626e1fd: UndoDeltaBlockGCOp(b69cec62913e474d8ffa850069e20034) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4}
I20260812 06:17:48.981467 22774 maintenance_manager.cc:419] P 842c220c1c944c669beef46d2626e1fd: Scheduling FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034): perf score=3.181125
I20260812 06:17:48.996729 22699 maintenance_manager.cc:643] P 842c220c1c944c669beef46d2626e1fd: FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034) complete. Timing: real 0.015s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4503,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:48.997231 22774 maintenance_manager.cc:419] P 842c220c1c944c669beef46d2626e1fd: Scheduling FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034): perf score=2.188937
I20260812 06:17:49.008637 22699 maintenance_manager.cc:643] P 842c220c1c944c669beef46d2626e1fd: FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034) complete. Timing: real 0.011s	user 0.007s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4205,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:49.009598 22774 maintenance_manager.cc:419] P 842c220c1c944c669beef46d2626e1fd: Scheduling MajorDeltaCompactionOp(b69cec62913e474d8ffa850069e20034): perf score=1.000000
I20260812 06:17:49.257396 22699 maintenance_manager.cc:643] P 842c220c1c944c669beef46d2626e1fd: MajorDeltaCompactionOp(b69cec62913e474d8ffa850069e20034) complete. Timing: real 0.248s	user 0.133s	sys 0.108s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32897810,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":2235,"lbm_read_time_us":18123,"lbm_reads_lt_1ms":774,"lbm_write_time_us":41102,"lbm_writes_lt_1ms":743,"mutex_wait_us":1561,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":4096,"thread_start_us":94,"threads_started":1,"update_count":3500}
I20260812 06:17:49.260807 22774 maintenance_manager.cc:419] P 842c220c1c944c669beef46d2626e1fd: Scheduling FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034): perf score=17.071750
I20260812 06:17:49.313463 22699 maintenance_manager.cc:643] P 842c220c1c944c669beef46d2626e1fd: FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034) complete. Timing: real 0.052s	user 0.040s	sys 0.008s Metrics: {"bytes_written":18666228,"delete_count":0,"lbm_write_time_us":22444,"lbm_writes_lt_1ms":458,"reinsert_count":0,"update_count":2275}
I20260812 06:17:49.313997 22774 maintenance_manager.cc:419] P 842c220c1c944c669beef46d2626e1fd: Scheduling FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034): perf score=1.196750
I20260812 06:17:49.329123 22699 maintenance_manager.cc:643] P 842c220c1c944c669beef46d2626e1fd: FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034) complete. Timing: real 0.015s	user 0.009s	sys 0.001s Metrics: {"bytes_written":2256533,"delete_count":0,"lbm_write_time_us":3794,"lbm_writes_lt_1ms":58,"reinsert_count":0,"update_count":275}
I20260812 06:17:49.329591 22774 maintenance_manager.cc:419] P 842c220c1c944c669beef46d2626e1fd: Scheduling FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034): perf score=2.188937
I20260812 06:17:49.340516 22699 maintenance_manager.cc:643] P 842c220c1c944c669beef46d2626e1fd: FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034) complete. Timing: real 0.011s	user 0.005s	sys 0.006s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4091,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:49.341054 22774 maintenance_manager.cc:419] P 842c220c1c944c669beef46d2626e1fd: Scheduling MajorDeltaCompactionOp(b69cec62913e474d8ffa850069e20034): perf score=1.000000
I20260812 06:17:49.553697 22699 maintenance_manager.cc:643] P 842c220c1c944c669beef46d2626e1fd: MajorDeltaCompactionOp(b69cec62913e474d8ffa850069e20034) complete. Timing: real 0.212s	user 0.153s	sys 0.059s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28795236,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":248,"lbm_read_time_us":15004,"lbm_reads_lt_1ms":673,"lbm_write_time_us":36394,"lbm_writes_lt_1ms":643,"mutex_wait_us":77,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":6400,"update_count":3000}
I20260812 06:17:49.554504 22774 maintenance_manager.cc:419] P 842c220c1c944c669beef46d2626e1fd: Scheduling FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034): perf score=14.095187
I20260812 06:17:49.605288 22699 maintenance_manager.cc:643] P 842c220c1c944c669beef46d2626e1fd: FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034) complete. Timing: real 0.051s	user 0.029s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22626,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:49.605814 22774 maintenance_manager.cc:419] P 842c220c1c944c669beef46d2626e1fd: Scheduling MajorDeltaCompactionOp(b69cec62913e474d8ffa850069e20034): perf score=1.000000
I20260812 06:17:49.753434 22699 maintenance_manager.cc:643] P 842c220c1c944c669beef46d2626e1fd: MajorDeltaCompactionOp(b69cec62913e474d8ffa850069e20034) complete. Timing: real 0.147s	user 0.078s	sys 0.068s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20590228,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":570,"lbm_read_time_us":9847,"lbm_reads_lt_1ms":463,"lbm_write_time_us":26201,"lbm_writes_lt_1ms":443,"mutex_wait_us":78,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:17:49.754238 22774 maintenance_manager.cc:419] P 842c220c1c944c669beef46d2626e1fd: Scheduling FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034): perf score=11.118625
I20260812 06:17:49.788722 22699 maintenance_manager.cc:643] P 842c220c1c944c669beef46d2626e1fd: FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034) complete. Timing: real 0.034s	user 0.018s	sys 0.015s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":14771,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:49.789470 22774 maintenance_manager.cc:419] P 842c220c1c944c669beef46d2626e1fd: Scheduling FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034): perf score=2.188937
I20260812 06:17:49.806037 22699 maintenance_manager.cc:643] P 842c220c1c944c669beef46d2626e1fd: FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034) complete. Timing: real 0.016s	user 0.012s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5540,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:49.806658 22774 maintenance_manager.cc:419] P 842c220c1c944c669beef46d2626e1fd: Scheduling MajorDeltaCompactionOp(b69cec62913e474d8ffa850069e20034): perf score=1.000000
I20260812 06:17:49.947546 22699 maintenance_manager.cc:643] P 842c220c1c944c669beef46d2626e1fd: MajorDeltaCompactionOp(b69cec62913e474d8ffa850069e20034) complete. Timing: real 0.141s	user 0.105s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590339,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":899,"lbm_read_time_us":10429,"lbm_reads_lt_1ms":464,"lbm_write_time_us":25209,"lbm_writes_lt_1ms":443,"mutex_wait_us":94,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2000}
I20260812 06:17:49.948431 22774 maintenance_manager.cc:419] P 842c220c1c944c669beef46d2626e1fd: Scheduling FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034): perf score=11.118625
I20260812 06:17:49.987763 22699 maintenance_manager.cc:643] P 842c220c1c944c669beef46d2626e1fd: FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034) complete. Timing: real 0.039s	user 0.026s	sys 0.009s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":16631,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:49.988536 22774 maintenance_manager.cc:419] P 842c220c1c944c669beef46d2626e1fd: Scheduling FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034): perf score=2.188937
I20260812 06:17:50.013407 22699 maintenance_manager.cc:643] P 842c220c1c944c669beef46d2626e1fd: FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034) complete. Timing: real 0.025s	user 0.004s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5131,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:50.013962 22774 maintenance_manager.cc:419] P 842c220c1c944c669beef46d2626e1fd: Scheduling FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034): perf score=2.188937
I20260812 06:17:50.025406 22699 maintenance_manager.cc:643] P 842c220c1c944c669beef46d2626e1fd: FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4295,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:50.025921 22774 maintenance_manager.cc:419] P 842c220c1c944c669beef46d2626e1fd: Scheduling MajorDeltaCompactionOp(b69cec62913e474d8ffa850069e20034): perf score=1.000000
I20260812 06:17:50.180189 22699 maintenance_manager.cc:643] P 842c220c1c944c669beef46d2626e1fd: MajorDeltaCompactionOp(b69cec62913e474d8ffa850069e20034) complete. Timing: real 0.154s	user 0.118s	sys 0.036s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24692869,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1101,"lbm_read_time_us":10355,"lbm_reads_lt_1ms":573,"lbm_write_time_us":30497,"lbm_writes_lt_1ms":543,"mutex_wait_us":538,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:17:50.181180 22774 maintenance_manager.cc:419] P 842c220c1c944c669beef46d2626e1fd: Scheduling FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034): perf score=10.126437
I20260812 06:17:50.213624 22699 maintenance_manager.cc:643] P 842c220c1c944c669beef46d2626e1fd: FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034) complete. Timing: real 0.032s	user 0.018s	sys 0.012s Metrics: {"bytes_written":12512611,"delete_count":0,"lbm_write_time_us":13990,"lbm_writes_lt_1ms":308,"reinsert_count":0,"update_count":1525}
I20260812 06:17:50.214147 22774 maintenance_manager.cc:419] P 842c220c1c944c669beef46d2626e1fd: Scheduling FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034): perf score=2.188937
I20260812 06:17:50.228229 22699 maintenance_manager.cc:643] P 842c220c1c944c669beef46d2626e1fd: FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034) complete. Timing: real 0.014s	user 0.013s	sys 0.000s Metrics: {"bytes_written":3897534,"delete_count":0,"lbm_write_time_us":4959,"lbm_writes_lt_1ms":98,"reinsert_count":0,"update_count":475}
I20260812 06:17:50.229069 22774 maintenance_manager.cc:419] P 842c220c1c944c669beef46d2626e1fd: Scheduling MajorDeltaCompactionOp(b69cec62913e474d8ffa850069e20034): perf score=1.000000
I20260812 06:17:50.362329 22699 maintenance_manager.cc:643] P 842c220c1c944c669beef46d2626e1fd: MajorDeltaCompactionOp(b69cec62913e474d8ffa850069e20034) complete. Timing: real 0.133s	user 0.105s	sys 0.028s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20590343,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":951,"lbm_read_time_us":9210,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25368,"lbm_writes_lt_1ms":443,"mutex_wait_us":25,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12288,"update_count":2000}
I20260812 06:17:50.363137 22774 maintenance_manager.cc:419] P 842c220c1c944c669beef46d2626e1fd: Scheduling FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034): perf score=10.126437
I20260812 06:17:50.418402 22699 maintenance_manager.cc:643] P 842c220c1c944c669beef46d2626e1fd: FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034) complete. Timing: real 0.055s	user 0.032s	sys 0.019s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":18128,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:17:50.419121 22774 maintenance_manager.cc:419] P 842c220c1c944c669beef46d2626e1fd: Scheduling FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034): perf score=2.188937
I20260812 06:17:50.430218 22699 maintenance_manager.cc:643] P 842c220c1c944c669beef46d2626e1fd: FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4400,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:50.430716 22774 maintenance_manager.cc:419] P 842c220c1c944c669beef46d2626e1fd: Scheduling FlushMRSOp(b69cec62913e474d8ffa850069e20034): perf score=1.000000
I20260812 06:17:50.471843 22699 maintenance_manager.cc:643] P 842c220c1c944c669beef46d2626e1fd: FlushMRSOp(b69cec62913e474d8ffa850069e20034) complete. Timing: real 0.041s	user 0.028s	sys 0.000s Metrics: {"bytes_written":1152512,"cfile_init":1,"dirs.queue_time_us":96,"dirs.run_cpu_time_us":247,"dirs.run_wall_time_us":1367,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1526,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:17:50.472630 22774 maintenance_manager.cc:419] P 842c220c1c944c669beef46d2626e1fd: Scheduling LogGCOp(b69cec62913e474d8ffa850069e20034): free 120553654 bytes of WAL
I20260812 06:17:50.472874 22699 log_reader.cc:385] T b69cec62913e474d8ffa850069e20034: removed 12 log segments from log reader
I20260812 06:17:50.472919 22699 log.cc:1079] T b69cec62913e474d8ffa850069e20034 P 842c220c1c944c669beef46d2626e1fd: Deleting log segment in path: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465356257-22570-0/minicluster-data/ts-0-root/wals/b69cec62913e474d8ffa850069e20034/wal-000000027 (ops 130-134)
I20260812 06:17:50.472950 22699 log.cc:1079] T b69cec62913e474d8ffa850069e20034 P 842c220c1c944c669beef46d2626e1fd: Deleting log segment in path: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465356257-22570-0/minicluster-data/ts-0-root/wals/b69cec62913e474d8ffa850069e20034/wal-000000028 (ops 135-138)
I20260812 06:17:50.473021 22699 log.cc:1079] T b69cec62913e474d8ffa850069e20034 P 842c220c1c944c669beef46d2626e1fd: Deleting log segment in path: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465356257-22570-0/minicluster-data/ts-0-root/wals/b69cec62913e474d8ffa850069e20034/wal-000000029 (ops 139-143)
I20260812 06:17:50.473054 22699 log.cc:1079] T b69cec62913e474d8ffa850069e20034 P 842c220c1c944c669beef46d2626e1fd: Deleting log segment in path: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465356257-22570-0/minicluster-data/ts-0-root/wals/b69cec62913e474d8ffa850069e20034/wal-000000030 (ops 144-148)
I20260812 06:17:50.473095 22699 log.cc:1079] T b69cec62913e474d8ffa850069e20034 P 842c220c1c944c669beef46d2626e1fd: Deleting log segment in path: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465356257-22570-0/minicluster-data/ts-0-root/wals/b69cec62913e474d8ffa850069e20034/wal-000000031 (ops 149-153)
I20260812 06:17:50.473152 22699 log.cc:1079] T b69cec62913e474d8ffa850069e20034 P 842c220c1c944c669beef46d2626e1fd: Deleting log segment in path: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465356257-22570-0/minicluster-data/ts-0-root/wals/b69cec62913e474d8ffa850069e20034/wal-000000032 (ops 154-158)
I20260812 06:17:50.473196 22699 log.cc:1079] T b69cec62913e474d8ffa850069e20034 P 842c220c1c944c669beef46d2626e1fd: Deleting log segment in path: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465356257-22570-0/minicluster-data/ts-0-root/wals/b69cec62913e474d8ffa850069e20034/wal-000000033 (ops 159-162)
I20260812 06:17:50.473235 22699 log.cc:1079] T b69cec62913e474d8ffa850069e20034 P 842c220c1c944c669beef46d2626e1fd: Deleting log segment in path: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465356257-22570-0/minicluster-data/ts-0-root/wals/b69cec62913e474d8ffa850069e20034/wal-000000034 (ops 163-167)
I20260812 06:17:50.473275 22699 log.cc:1079] T b69cec62913e474d8ffa850069e20034 P 842c220c1c944c669beef46d2626e1fd: Deleting log segment in path: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465356257-22570-0/minicluster-data/ts-0-root/wals/b69cec62913e474d8ffa850069e20034/wal-000000035 (ops 168-172)
I20260812 06:17:50.473315 22699 log.cc:1079] T b69cec62913e474d8ffa850069e20034 P 842c220c1c944c669beef46d2626e1fd: Deleting log segment in path: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465356257-22570-0/minicluster-data/ts-0-root/wals/b69cec62913e474d8ffa850069e20034/wal-000000036 (ops 173-177)
I20260812 06:17:50.473354 22699 log.cc:1079] T b69cec62913e474d8ffa850069e20034 P 842c220c1c944c669beef46d2626e1fd: Deleting log segment in path: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465356257-22570-0/minicluster-data/ts-0-root/wals/b69cec62913e474d8ffa850069e20034/wal-000000037 (ops 178-182)
I20260812 06:17:50.473393 22699 log.cc:1079] T b69cec62913e474d8ffa850069e20034 P 842c220c1c944c669beef46d2626e1fd: Deleting log segment in path: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515465356257-22570-0/minicluster-data/ts-0-root/wals/b69cec62913e474d8ffa850069e20034/wal-000000038 (ops 183-187)
I20260812 06:17:50.500312 22699 maintenance_manager.cc:643] P 842c220c1c944c669beef46d2626e1fd: LogGCOp(b69cec62913e474d8ffa850069e20034) complete. Timing: real 0.027s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:17:50.500712 22774 maintenance_manager.cc:419] P 842c220c1c944c669beef46d2626e1fd: Scheduling UndoDeltaBlockGCOp(b69cec62913e474d8ffa850069e20034): 447 bytes on disk
I20260812 06:17:50.501157 22699 maintenance_manager.cc:643] P 842c220c1c944c669beef46d2626e1fd: UndoDeltaBlockGCOp(b69cec62913e474d8ffa850069e20034) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":58,"lbm_reads_lt_1ms":4}
I20260812 06:17:50.501748 22774 maintenance_manager.cc:419] P 842c220c1c944c669beef46d2626e1fd: Scheduling FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034): perf score=2.188937
I20260812 06:17:50.522826 22699 maintenance_manager.cc:643] P 842c220c1c944c669beef46d2626e1fd: FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034) complete. Timing: real 0.021s	user 0.008s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6425,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:50.523345 22774 maintenance_manager.cc:419] P 842c220c1c944c669beef46d2626e1fd: Scheduling FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034): perf score=2.188937
I20260812 06:17:50.534277 22699 maintenance_manager.cc:643] P 842c220c1c944c669beef46d2626e1fd: FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4189,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:50.534778 22774 maintenance_manager.cc:419] P 842c220c1c944c669beef46d2626e1fd: Scheduling MajorDeltaCompactionOp(b69cec62913e474d8ffa850069e20034): perf score=1.000000
I20260812 06:17:50.734452 22699 maintenance_manager.cc:643] P 842c220c1c944c669beef46d2626e1fd: MajorDeltaCompactionOp(b69cec62913e474d8ffa850069e20034) complete. Timing: real 0.199s	user 0.135s	sys 0.063s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28795410,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1440,"lbm_read_time_us":14569,"lbm_reads_lt_1ms":674,"lbm_write_time_us":31799,"lbm_writes_lt_1ms":643,"mutex_wait_us":593,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":6656,"thread_start_us":86,"threads_started":1,"update_count":3000}
I20260812 06:17:50.735370 22774 maintenance_manager.cc:419] P 842c220c1c944c669beef46d2626e1fd: Scheduling FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034): perf score=14.095187
I20260812 06:17:50.796996 22570 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.098s	user 1.793s	sys 0.162s
I20260812 06:17:50.804870 22699 maintenance_manager.cc:643] P 842c220c1c944c669beef46d2626e1fd: FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034) complete. Timing: real 0.069s	user 0.033s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":45719,"lbm_writes_1-10_ms":1,"lbm_writes_10-100_ms":1,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:17:50.805408 22774 maintenance_manager.cc:419] P 842c220c1c944c669beef46d2626e1fd: Scheduling FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034): perf score=2.188937
I20260812 06:17:50.815560 22699 maintenance_manager.cc:643] P 842c220c1c944c669beef46d2626e1fd: FlushDeltaMemStoresOp(b69cec62913e474d8ffa850069e20034) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4031,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:50.816131 22774 maintenance_manager.cc:419] P 842c220c1c944c669beef46d2626e1fd: Scheduling MajorDeltaCompactionOp(b69cec62913e474d8ffa850069e20034): perf score=1.000000
I20260812 06:17:50.840931 22570 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.043s	user 0.005s	sys 0.000s
I20260812 06:17:50.841801 22570 tablet_server.cc:179] TabletServer@127.22.10.129:0 shutting down...
I20260812 06:17:50.974251 22699 maintenance_manager.cc:643] P 842c220c1c944c669beef46d2626e1fd: MajorDeltaCompactionOp(b69cec62913e474d8ffa850069e20034) complete. Timing: real 0.158s	user 0.104s	sys 0.053s Metrics: {"cfile_cache_hit":30,"cfile_cache_hit_bytes":4180460,"cfile_cache_miss":502,"cfile_cache_miss_bytes":20512298,"cfile_init":4,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":635,"lbm_read_time_us":8795,"lbm_reads_lt_1ms":518,"lbm_write_time_us":29448,"lbm_writes_lt_1ms":543,"mutex_wait_us":122,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":58624,"update_count":2500}
I20260812 06:17:50.975033 22570 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:50.975468 22570 tablet_replica.cc:333] T b69cec62913e474d8ffa850069e20034 P 842c220c1c944c669beef46d2626e1fd: stopping tablet replica
I20260812 06:17:50.975724 22570 raft_consensus.cc:2243] T b69cec62913e474d8ffa850069e20034 P 842c220c1c944c669beef46d2626e1fd [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:50.975965 22570 raft_consensus.cc:2272] T b69cec62913e474d8ffa850069e20034 P 842c220c1c944c669beef46d2626e1fd [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:50.992337 22570 tablet_server.cc:196] TabletServer@127.22.10.129:0 shutdown complete.
I20260812 06:17:51.021349 22570 master.cc:562] Master@127.22.10.190:35373 shutting down...
I20260812 06:17:51.025679 22570 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 898352f0a292406e8f656d5c1cd2c099 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:51.025867 22570 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 898352f0a292406e8f656d5c1cd2c099 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:51.025923 22570 tablet_replica.cc:333] T 00000000000000000000000000000000 P 898352f0a292406e8f656d5c1cd2c099: stopping tablet replica
I20260812 06:17:51.038444 22570 master.cc:584] Master@127.22.10.190:35373 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5765 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:17:51.133073 22570 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.22.10.190:33235
I20260812 06:17:51.133430 22570 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:51.135450 22814 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:51.135560 22810 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:51.135648 22811 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:51.135686 22570 server_base.cc:1061] running on GCE node
I20260812 06:17:51.135890 22570 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:51.135933 22570 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:51.135948 22570 hybrid_clock.cc:648] HybridClock initialized: now 1786515471135949 us; error 0 us; skew 500 ppm
I20260812 06:17:51.136822 22570 webserver.cc:533] Webserver started at http://127.22.10.190:37541/ using document root <none> and password file <none>
I20260812 06:17:51.137005 22570 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:51.137091 22570 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:51.137228 22570 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:51.137646 22570 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465356257-22570-0/minicluster-data/master-0-root/instance:
uuid: "dc521b9d88e345d19960c5eb8c778d5f"
format_stamp: "Formatted at 2026-08-12 06:17:51 on dist-test-slave-1zqn"
I20260812 06:17:51.139212 22570 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:17:51.140240 22820 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:51.140482 22570 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:17:51.140575 22570 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465356257-22570-0/minicluster-data/master-0-root
uuid: "dc521b9d88e345d19960c5eb8c778d5f"
format_stamp: "Formatted at 2026-08-12 06:17:51 on dist-test-slave-1zqn"
I20260812 06:17:51.140673 22570 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465356257-22570-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465356257-22570-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465356257-22570-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:51.157007 22570 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:51.157480 22570 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:51.161891 22570 rpc_server.cc:307] RPC server started. Bound to: 127.22.10.190:33235
I20260812 06:17:51.164866 22878 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.22.10.190:33235 every 8 connection(s)
I20260812 06:17:51.166177 22879 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:51.181569 22879 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P dc521b9d88e345d19960c5eb8c778d5f: Bootstrap starting.
I20260812 06:17:51.182533 22879 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P dc521b9d88e345d19960c5eb8c778d5f: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:51.183745 22879 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P dc521b9d88e345d19960c5eb8c778d5f: No bootstrap required, opened a new log
I20260812 06:17:51.184243 22879 raft_consensus.cc:359] T 00000000000000000000000000000000 P dc521b9d88e345d19960c5eb8c778d5f [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "dc521b9d88e345d19960c5eb8c778d5f" member_type: VOTER }
I20260812 06:17:51.184342 22879 raft_consensus.cc:385] T 00000000000000000000000000000000 P dc521b9d88e345d19960c5eb8c778d5f [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:51.184367 22879 raft_consensus.cc:740] T 00000000000000000000000000000000 P dc521b9d88e345d19960c5eb8c778d5f [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: dc521b9d88e345d19960c5eb8c778d5f, State: Initialized, Role: FOLLOWER
I20260812 06:17:51.184492 22879 consensus_queue.cc:260] T 00000000000000000000000000000000 P dc521b9d88e345d19960c5eb8c778d5f [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: "dc521b9d88e345d19960c5eb8c778d5f" member_type: VOTER }
I20260812 06:17:51.184598 22879 raft_consensus.cc:399] T 00000000000000000000000000000000 P dc521b9d88e345d19960c5eb8c778d5f [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:51.184649 22879 raft_consensus.cc:493] T 00000000000000000000000000000000 P dc521b9d88e345d19960c5eb8c778d5f [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:51.184705 22879 raft_consensus.cc:3060] T 00000000000000000000000000000000 P dc521b9d88e345d19960c5eb8c778d5f [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:51.185516 22879 raft_consensus.cc:515] T 00000000000000000000000000000000 P dc521b9d88e345d19960c5eb8c778d5f [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "dc521b9d88e345d19960c5eb8c778d5f" member_type: VOTER }
I20260812 06:17:51.185645 22879 leader_election.cc:304] T 00000000000000000000000000000000 P dc521b9d88e345d19960c5eb8c778d5f [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: dc521b9d88e345d19960c5eb8c778d5f; no voters: 
I20260812 06:17:51.185828 22879 leader_election.cc:290] T 00000000000000000000000000000000 P dc521b9d88e345d19960c5eb8c778d5f [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:51.185974 22883 raft_consensus.cc:2804] T 00000000000000000000000000000000 P dc521b9d88e345d19960c5eb8c778d5f [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:51.186231 22883 raft_consensus.cc:697] T 00000000000000000000000000000000 P dc521b9d88e345d19960c5eb8c778d5f [term 1 LEADER]: Becoming Leader. State: Replica: dc521b9d88e345d19960c5eb8c778d5f, State: Running, Role: LEADER
I20260812 06:17:51.186379 22883 consensus_queue.cc:237] T 00000000000000000000000000000000 P dc521b9d88e345d19960c5eb8c778d5f [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: "dc521b9d88e345d19960c5eb8c778d5f" member_type: VOTER }
I20260812 06:17:51.186487 22879 sys_catalog.cc:565] T 00000000000000000000000000000000 P dc521b9d88e345d19960c5eb8c778d5f [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:17:51.186836 22885 sys_catalog.cc:455] T 00000000000000000000000000000000 P dc521b9d88e345d19960c5eb8c778d5f [sys.catalog]: SysCatalogTable state changed. Reason: New leader dc521b9d88e345d19960c5eb8c778d5f. Latest consensus state: current_term: 1 leader_uuid: "dc521b9d88e345d19960c5eb8c778d5f" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "dc521b9d88e345d19960c5eb8c778d5f" member_type: VOTER } }
I20260812 06:17:51.186877 22884 sys_catalog.cc:455] T 00000000000000000000000000000000 P dc521b9d88e345d19960c5eb8c778d5f [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "dc521b9d88e345d19960c5eb8c778d5f" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "dc521b9d88e345d19960c5eb8c778d5f" member_type: VOTER } }
I20260812 06:17:51.187006 22885 sys_catalog.cc:458] T 00000000000000000000000000000000 P dc521b9d88e345d19960c5eb8c778d5f [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:51.187093 22884 sys_catalog.cc:458] T 00000000000000000000000000000000 P dc521b9d88e345d19960c5eb8c778d5f [sys.catalog]: This master's current role is: LEADER
I20260812 06:17:51.187805 22887 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:17:51.189024 22887 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:17:51.189292 22570 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:17:51.191372 22887 catalog_manager.cc:1383] Generated new cluster ID: 714ffa0c39084721841545f4ed1ff148
I20260812 06:17:51.191442 22887 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:17:51.203006 22887 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:17:51.203568 22887 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:17:51.213532 22887 catalog_manager.cc:6092] T 00000000000000000000000000000000 P dc521b9d88e345d19960c5eb8c778d5f: Generated new TSK 0
I20260812 06:17:51.213790 22887 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:17:51.221750 22570 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:17:51.223923 22906 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:17:51.223960 22570 server_base.cc:1061] running on GCE node
W20260812 06:17:51.224017 22907 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:17:51.224198 22909 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:17:51.224459 22570 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:17:51.224525 22570 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:17:51.224543 22570 hybrid_clock.cc:648] HybridClock initialized: now 1786515471224544 us; error 0 us; skew 500 ppm
I20260812 06:17:51.225425 22570 webserver.cc:533] Webserver started at http://127.22.10.129:40195/ using document root <none> and password file <none>
I20260812 06:17:51.225579 22570 fs_manager.cc:362] Metadata directory not provided
I20260812 06:17:51.225625 22570 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:17:51.225682 22570 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:17:51.226109 22570 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465356257-22570-0/minicluster-data/ts-0-root/instance:
uuid: "74e80787f39d49b4864529528064e17d"
format_stamp: "Formatted at 2026-08-12 06:17:51 on dist-test-slave-1zqn"
I20260812 06:17:51.227571 22570 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:17:51.228579 22914 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:51.228827 22570 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.000s
I20260812 06:17:51.228892 22570 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465356257-22570-0/minicluster-data/ts-0-root
uuid: "74e80787f39d49b4864529528064e17d"
format_stamp: "Formatted at 2026-08-12 06:17:51 on dist-test-slave-1zqn"
I20260812 06:17:51.228950 22570 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465356257-22570-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465356257-22570-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465356257-22570-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:17:51.244539 22570 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:17:51.244918 22570 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:17:51.245213 22570 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:17:51.245741 22570 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:17:51.245782 22570 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:51.245848 22570 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:17:51.245893 22570 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:17:51.250574 22570 rpc_server.cc:307] RPC server started. Bound to: 127.22.10.129:34277
I20260812 06:17:51.250651 22984 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.22.10.129:34277 every 8 connection(s)
I20260812 06:17:51.256008 22985 heartbeater.cc:344] Connected to a master server at 127.22.10.190:33235
I20260812 06:17:51.256182 22985 heartbeater.cc:461] Registering TS with master...
I20260812 06:17:51.256458 22985 heartbeater.cc:507] Master 127.22.10.190:33235 requested a full tablet report, sending...
I20260812 06:17:51.257217 22838 ts_manager.cc:194] Registered new tserver with Master: 74e80787f39d49b4864529528064e17d (127.22.10.129:34277)
I20260812 06:17:51.257761 22570 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.006714179s
I20260812 06:17:51.258076 22838 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:43734
I20260812 06:17:51.265163 22838 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:43746:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:17:51.276033 22946 tablet_service.cc:1511] Processing CreateTablet for tablet 6a646a4d1f634b23b8beb277ed2c7579 (DEFAULT_TABLE table=heavy-update-compaction-test [id=cabc6680d6d04ca6ae96c2fc9635559c]), partition=
I20260812 06:17:51.276419 22946 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 6a646a4d1f634b23b8beb277ed2c7579. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:17:51.278780 23000 tablet_bootstrap.cc:492] T 6a646a4d1f634b23b8beb277ed2c7579 P 74e80787f39d49b4864529528064e17d: Bootstrap starting.
I20260812 06:17:51.279662 23000 tablet_bootstrap.cc:654] T 6a646a4d1f634b23b8beb277ed2c7579 P 74e80787f39d49b4864529528064e17d: Neither blocks nor log segments found. Creating new log.
I20260812 06:17:51.280894 23000 tablet_bootstrap.cc:492] T 6a646a4d1f634b23b8beb277ed2c7579 P 74e80787f39d49b4864529528064e17d: No bootstrap required, opened a new log
I20260812 06:17:51.281001 23000 ts_tablet_manager.cc:1403] T 6a646a4d1f634b23b8beb277ed2c7579 P 74e80787f39d49b4864529528064e17d: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:17:51.281459 23000 raft_consensus.cc:359] T 6a646a4d1f634b23b8beb277ed2c7579 P 74e80787f39d49b4864529528064e17d [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "74e80787f39d49b4864529528064e17d" member_type: VOTER last_known_addr { host: "127.22.10.129" port: 34277 } }
I20260812 06:17:51.281584 23000 raft_consensus.cc:385] T 6a646a4d1f634b23b8beb277ed2c7579 P 74e80787f39d49b4864529528064e17d [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:17:51.281634 23000 raft_consensus.cc:740] T 6a646a4d1f634b23b8beb277ed2c7579 P 74e80787f39d49b4864529528064e17d [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 74e80787f39d49b4864529528064e17d, State: Initialized, Role: FOLLOWER
I20260812 06:17:51.281773 23000 consensus_queue.cc:260] T 6a646a4d1f634b23b8beb277ed2c7579 P 74e80787f39d49b4864529528064e17d [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: "74e80787f39d49b4864529528064e17d" member_type: VOTER last_known_addr { host: "127.22.10.129" port: 34277 } }
I20260812 06:17:51.281879 23000 raft_consensus.cc:399] T 6a646a4d1f634b23b8beb277ed2c7579 P 74e80787f39d49b4864529528064e17d [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:17:51.281924 23000 raft_consensus.cc:493] T 6a646a4d1f634b23b8beb277ed2c7579 P 74e80787f39d49b4864529528064e17d [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:17:51.281980 23000 raft_consensus.cc:3060] T 6a646a4d1f634b23b8beb277ed2c7579 P 74e80787f39d49b4864529528064e17d [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:17:51.282707 23000 raft_consensus.cc:515] T 6a646a4d1f634b23b8beb277ed2c7579 P 74e80787f39d49b4864529528064e17d [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "74e80787f39d49b4864529528064e17d" member_type: VOTER last_known_addr { host: "127.22.10.129" port: 34277 } }
I20260812 06:17:51.282866 23000 leader_election.cc:304] T 6a646a4d1f634b23b8beb277ed2c7579 P 74e80787f39d49b4864529528064e17d [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: 74e80787f39d49b4864529528064e17d; no voters: 
I20260812 06:17:51.283079 23000 leader_election.cc:290] T 6a646a4d1f634b23b8beb277ed2c7579 P 74e80787f39d49b4864529528064e17d [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:17:51.283215 23003 raft_consensus.cc:2804] T 6a646a4d1f634b23b8beb277ed2c7579 P 74e80787f39d49b4864529528064e17d [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:17:51.283457 22985 heartbeater.cc:499] Master 127.22.10.190:33235 was elected leader, sending a full tablet report...
I20260812 06:17:51.283433 23000 ts_tablet_manager.cc:1434] T 6a646a4d1f634b23b8beb277ed2c7579 P 74e80787f39d49b4864529528064e17d: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:17:51.283447 23003 raft_consensus.cc:697] T 6a646a4d1f634b23b8beb277ed2c7579 P 74e80787f39d49b4864529528064e17d [term 1 LEADER]: Becoming Leader. State: Replica: 74e80787f39d49b4864529528064e17d, State: Running, Role: LEADER
I20260812 06:17:51.283712 23003 consensus_queue.cc:237] T 6a646a4d1f634b23b8beb277ed2c7579 P 74e80787f39d49b4864529528064e17d [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: "74e80787f39d49b4864529528064e17d" member_type: VOTER last_known_addr { host: "127.22.10.129" port: 34277 } }
I20260812 06:17:51.285218 22838 catalog_manager.cc:5719] T 6a646a4d1f634b23b8beb277ed2c7579 P 74e80787f39d49b4864529528064e17d reported cstate change: term changed from 0 to 1, leader changed from <none> to 74e80787f39d49b4864529528064e17d (127.22.10.129). New cstate: current_term: 1 leader_uuid: "74e80787f39d49b4864529528064e17d" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "74e80787f39d49b4864529528064e17d" member_type: VOTER last_known_addr { host: "127.22.10.129" port: 34277 } health_report { overall_health: HEALTHY } } }
I20260812 06:17:51.347350 22570 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.056s	user 0.019s	sys 0.004s
I20260812 06:17:51.501770 22986 maintenance_manager.cc:419] P 74e80787f39d49b4864529528064e17d: Scheduling FlushMRSOp(6a646a4d1f634b23b8beb277ed2c7579): perf score=19.054940
I20260812 06:17:51.659123 22922 maintenance_manager.cc:643] P 74e80787f39d49b4864529528064e17d: FlushMRSOp(6a646a4d1f634b23b8beb277ed2c7579) complete. Timing: real 0.157s	user 0.117s	sys 0.037s Metrics: {"bytes_written":12307493,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":117,"dirs.run_cpu_time_us":269,"dirs.run_wall_time_us":1017,"drs_written":1,"lbm_read_time_us":40,"lbm_reads_lt_1ms":4,"lbm_write_time_us":43086,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1500}
I20260812 06:17:51.659799 22986 maintenance_manager.cc:419] P 74e80787f39d49b4864529528064e17d: Scheduling LogGCOp(6a646a4d1f634b23b8beb277ed2c7579): free 20743831 bytes of WAL
I20260812 06:17:51.660162 22922 log_reader.cc:385] T 6a646a4d1f634b23b8beb277ed2c7579: removed 2 log segments from log reader
I20260812 06:17:51.660290 22922 log.cc:1079] T 6a646a4d1f634b23b8beb277ed2c7579 P 74e80787f39d49b4864529528064e17d: Deleting log segment in path: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465356257-22570-0/minicluster-data/ts-0-root/wals/6a646a4d1f634b23b8beb277ed2c7579/wal-000000001 (ops 1-6)
I20260812 06:17:51.660396 22922 log.cc:1079] T 6a646a4d1f634b23b8beb277ed2c7579 P 74e80787f39d49b4864529528064e17d: Deleting log segment in path: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465356257-22570-0/minicluster-data/ts-0-root/wals/6a646a4d1f634b23b8beb277ed2c7579/wal-000000002 (ops 7-11)
I20260812 06:17:51.666229 22922 maintenance_manager.cc:643] P 74e80787f39d49b4864529528064e17d: LogGCOp(6a646a4d1f634b23b8beb277ed2c7579) complete. Timing: real 0.006s	user 0.001s	sys 0.003s Metrics: {}
I20260812 06:17:51.666697 22986 maintenance_manager.cc:419] P 74e80787f39d49b4864529528064e17d: Scheduling FlushDeltaMemStoresOp(6a646a4d1f634b23b8beb277ed2c7579): perf score=2.188937
I20260812 06:17:51.689980 22922 maintenance_manager.cc:643] P 74e80787f39d49b4864529528064e17d: FlushDeltaMemStoresOp(6a646a4d1f634b23b8beb277ed2c7579) complete. Timing: real 0.023s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4338,"lbm_writes_lt_1ms":103,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":500}
I20260812 06:17:51.690493 22986 maintenance_manager.cc:419] P 74e80787f39d49b4864529528064e17d: Scheduling FlushDeltaMemStoresOp(6a646a4d1f634b23b8beb277ed2c7579): perf score=2.188937
I20260812 06:17:51.705760 22922 maintenance_manager.cc:643] P 74e80787f39d49b4864529528064e17d: FlushDeltaMemStoresOp(6a646a4d1f634b23b8beb277ed2c7579) complete. Timing: real 0.015s	user 0.006s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5863,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:51.706447 22986 maintenance_manager.cc:419] P 74e80787f39d49b4864529528064e17d: Scheduling UndoDeltaBlockGCOp(6a646a4d1f634b23b8beb277ed2c7579): 16411398 bytes on disk
I20260812 06:17:51.706918 22922 maintenance_manager.cc:643] P 74e80787f39d49b4864529528064e17d: UndoDeltaBlockGCOp(6a646a4d1f634b23b8beb277ed2c7579) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":64,"lbm_reads_lt_1ms":4}
I20260812 06:17:51.707342 22986 maintenance_manager.cc:419] P 74e80787f39d49b4864529528064e17d: Scheduling MajorDeltaCompactionOp(6a646a4d1f634b23b8beb277ed2c7579): perf score=1.000000
I20260812 06:17:51.895829 22922 maintenance_manager.cc:643] P 74e80787f39d49b4864529528064e17d: MajorDeltaCompactionOp(6a646a4d1f634b23b8beb277ed2c7579) complete. Timing: real 0.188s	user 0.115s	sys 0.067s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774811,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1573,"lbm_read_time_us":12632,"lbm_reads_lt_1ms":569,"lbm_write_time_us":28997,"lbm_writes_lt_1ms":543,"mutex_wait_us":309,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2048,"thread_start_us":401,"threads_started":5,"update_count":2500}
I20260812 06:17:51.896481 22986 maintenance_manager.cc:419] P 74e80787f39d49b4864529528064e17d: Scheduling FlushDeltaMemStoresOp(6a646a4d1f634b23b8beb277ed2c7579): perf score=11.118625
I20260812 06:17:51.933578 22922 maintenance_manager.cc:643] P 74e80787f39d49b4864529528064e17d: FlushDeltaMemStoresOp(6a646a4d1f634b23b8beb277ed2c7579) complete. Timing: real 0.037s	user 0.028s	sys 0.007s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15661,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:51.934273 22986 maintenance_manager.cc:419] P 74e80787f39d49b4864529528064e17d: Scheduling FlushDeltaMemStoresOp(6a646a4d1f634b23b8beb277ed2c7579): perf score=2.188937
I20260812 06:17:51.950294 22922 maintenance_manager.cc:643] P 74e80787f39d49b4864529528064e17d: FlushDeltaMemStoresOp(6a646a4d1f634b23b8beb277ed2c7579) complete. Timing: real 0.016s	user 0.009s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5650,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:51.950759 22986 maintenance_manager.cc:419] P 74e80787f39d49b4864529528064e17d: Scheduling MajorDeltaCompactionOp(6a646a4d1f634b23b8beb277ed2c7579): perf score=1.000000
I20260812 06:17:52.080598 22922 maintenance_manager.cc:643] P 74e80787f39d49b4864529528064e17d: MajorDeltaCompactionOp(6a646a4d1f634b23b8beb277ed2c7579) complete. Timing: real 0.130s	user 0.111s	sys 0.016s 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":482,"lbm_read_time_us":7802,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24280,"lbm_writes_lt_1ms":443,"mutex_wait_us":49,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9472,"update_count":2000}
I20260812 06:17:52.081447 22986 maintenance_manager.cc:419] P 74e80787f39d49b4864529528064e17d: Scheduling FlushDeltaMemStoresOp(6a646a4d1f634b23b8beb277ed2c7579): perf score=11.118625
I20260812 06:17:52.116585 22922 maintenance_manager.cc:643] P 74e80787f39d49b4864529528064e17d: FlushDeltaMemStoresOp(6a646a4d1f634b23b8beb277ed2c7579) complete. Timing: real 0.035s	user 0.019s	sys 0.016s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15307,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:17:52.117368 22986 maintenance_manager.cc:419] P 74e80787f39d49b4864529528064e17d: Scheduling FlushDeltaMemStoresOp(6a646a4d1f634b23b8beb277ed2c7579): perf score=2.188937
I20260812 06:17:52.134075 22922 maintenance_manager.cc:643] P 74e80787f39d49b4864529528064e17d: FlushDeltaMemStoresOp(6a646a4d1f634b23b8beb277ed2c7579) complete. Timing: real 0.016s	user 0.010s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6168,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:52.134586 22986 maintenance_manager.cc:419] P 74e80787f39d49b4864529528064e17d: Scheduling MajorDeltaCompactionOp(6a646a4d1f634b23b8beb277ed2c7579): perf score=1.000000
I20260812 06:17:52.286756 22922 maintenance_manager.cc:643] P 74e80787f39d49b4864529528064e17d: MajorDeltaCompactionOp(6a646a4d1f634b23b8beb277ed2c7579) complete. Timing: real 0.152s	user 0.126s	sys 0.016s 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":1062,"lbm_read_time_us":9070,"lbm_reads_lt_1ms":464,"lbm_write_time_us":27384,"lbm_writes_lt_1ms":443,"mutex_wait_us":326,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":16896,"update_count":2000}
I20260812 06:17:52.287523 22986 maintenance_manager.cc:419] P 74e80787f39d49b4864529528064e17d: Scheduling FlushDeltaMemStoresOp(6a646a4d1f634b23b8beb277ed2c7579): perf score=14.095187
I20260812 06:17:52.341255 22922 maintenance_manager.cc:643] P 74e80787f39d49b4864529528064e17d: FlushDeltaMemStoresOp(6a646a4d1f634b23b8beb277ed2c7579) complete. Timing: real 0.054s	user 0.023s	sys 0.024s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21618,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:52.341884 22986 maintenance_manager.cc:419] P 74e80787f39d49b4864529528064e17d: Scheduling FlushDeltaMemStoresOp(6a646a4d1f634b23b8beb277ed2c7579): perf score=2.188937
I20260812 06:17:52.354229 22922 maintenance_manager.cc:643] P 74e80787f39d49b4864529528064e17d: FlushDeltaMemStoresOp(6a646a4d1f634b23b8beb277ed2c7579) complete. Timing: real 0.012s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4567,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:52.354898 22986 maintenance_manager.cc:419] P 74e80787f39d49b4864529528064e17d: Scheduling MajorDeltaCompactionOp(6a646a4d1f634b23b8beb277ed2c7579): perf score=1.000000
I20260812 06:17:52.519613 22922 maintenance_manager.cc:643] P 74e80787f39d49b4864529528064e17d: MajorDeltaCompactionOp(6a646a4d1f634b23b8beb277ed2c7579) complete. Timing: real 0.165s	user 0.143s	sys 0.020s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1315,"lbm_read_time_us":10714,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30840,"lbm_writes_lt_1ms":543,"mutex_wait_us":359,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4352,"update_count":2500}
I20260812 06:17:52.520521 22986 maintenance_manager.cc:419] P 74e80787f39d49b4864529528064e17d: Scheduling FlushDeltaMemStoresOp(6a646a4d1f634b23b8beb277ed2c7579): perf score=12.110812
I20260812 06:17:52.573167 22922 maintenance_manager.cc:643] P 74e80787f39d49b4864529528064e17d: FlushDeltaMemStoresOp(6a646a4d1f634b23b8beb277ed2c7579) complete. Timing: real 0.052s	user 0.035s	sys 0.016s Metrics: {"bytes_written":14481770,"delete_count":0,"lbm_write_time_us":23569,"lbm_writes_lt_1ms":356,"mutex_wait_us":675,"reinsert_count":0,"update_count":1765}
I20260812 06:17:52.573722 22986 maintenance_manager.cc:419] P 74e80787f39d49b4864529528064e17d: Scheduling FlushDeltaMemStoresOp(6a646a4d1f634b23b8beb277ed2c7579): perf score=1.000000
I20260812 06:17:52.587615 22922 maintenance_manager.cc:643] P 74e80787f39d49b4864529528064e17d: FlushDeltaMemStoresOp(6a646a4d1f634b23b8beb277ed2c7579) complete. Timing: real 0.014s	user 0.004s	sys 0.004s Metrics: {"bytes_written":1928327,"delete_count":0,"lbm_write_time_us":3618,"lbm_writes_lt_1ms":50,"reinsert_count":0,"update_count":235}
I20260812 06:17:52.588279 22986 maintenance_manager.cc:419] P 74e80787f39d49b4864529528064e17d: Scheduling MajorDeltaCompactionOp(6a646a4d1f634b23b8beb277ed2c7579): perf score=1.000000
I20260812 06:17:52.754942 22922 maintenance_manager.cc:643] P 74e80787f39d49b4864529528064e17d: MajorDeltaCompactionOp(6a646a4d1f634b23b8beb277ed2c7579) complete. Timing: real 0.166s	user 0.116s	sys 0.045s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672226,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":677,"lbm_read_time_us":11526,"lbm_reads_lt_1ms":464,"lbm_write_time_us":28529,"lbm_writes_lt_1ms":443,"mutex_wait_us":299,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7808,"update_count":2000}
I20260812 06:17:52.755749 22986 maintenance_manager.cc:419] P 74e80787f39d49b4864529528064e17d: Scheduling FlushDeltaMemStoresOp(6a646a4d1f634b23b8beb277ed2c7579): perf score=14.095187
I20260812 06:17:52.809399 22922 maintenance_manager.cc:643] P 74e80787f39d49b4864529528064e17d: FlushDeltaMemStoresOp(6a646a4d1f634b23b8beb277ed2c7579) complete. Timing: real 0.053s	user 0.028s	sys 0.019s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":22341,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:17:52.809970 22986 maintenance_manager.cc:419] P 74e80787f39d49b4864529528064e17d: Scheduling FlushDeltaMemStoresOp(6a646a4d1f634b23b8beb277ed2c7579): perf score=2.188937
I20260812 06:17:52.832239 22922 maintenance_manager.cc:643] P 74e80787f39d49b4864529528064e17d: FlushDeltaMemStoresOp(6a646a4d1f634b23b8beb277ed2c7579) complete. Timing: real 0.022s	user 0.014s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4075,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:52.832826 22986 maintenance_manager.cc:419] P 74e80787f39d49b4864529528064e17d: Scheduling MajorDeltaCompactionOp(6a646a4d1f634b23b8beb277ed2c7579): perf score=1.000000
I20260812 06:17:53.014684 22922 maintenance_manager.cc:643] P 74e80787f39d49b4864529528064e17d: MajorDeltaCompactionOp(6a646a4d1f634b23b8beb277ed2c7579) complete. Timing: real 0.182s	user 0.136s	sys 0.045s 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":324,"lbm_read_time_us":11898,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29462,"lbm_writes_lt_1ms":543,"mutex_wait_us":45,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5504,"update_count":2500}
I20260812 06:17:53.015244 22986 maintenance_manager.cc:419] P 74e80787f39d49b4864529528064e17d: Scheduling FlushDeltaMemStoresOp(6a646a4d1f634b23b8beb277ed2c7579): perf score=14.095187
I20260812 06:17:53.059680 22922 maintenance_manager.cc:643] P 74e80787f39d49b4864529528064e17d: FlushDeltaMemStoresOp(6a646a4d1f634b23b8beb277ed2c7579) complete. Timing: real 0.044s	user 0.029s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19445,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2000}
I20260812 06:17:53.060319 22986 maintenance_manager.cc:419] P 74e80787f39d49b4864529528064e17d: Scheduling FlushDeltaMemStoresOp(6a646a4d1f634b23b8beb277ed2c7579): perf score=2.188937
I20260812 06:17:53.076740 22922 maintenance_manager.cc:643] P 74e80787f39d49b4864529528064e17d: FlushDeltaMemStoresOp(6a646a4d1f634b23b8beb277ed2c7579) complete. Timing: real 0.016s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6516,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:53.077448 22986 maintenance_manager.cc:419] P 74e80787f39d49b4864529528064e17d: Scheduling FlushMRSOp(6a646a4d1f634b23b8beb277ed2c7579): perf score=1.000000
I20260812 06:17:53.118103 22922 maintenance_manager.cc:643] P 74e80787f39d49b4864529528064e17d: FlushMRSOp(6a646a4d1f634b23b8beb277ed2c7579) complete. Timing: real 0.040s	user 0.028s	sys 0.006s Metrics: {"bytes_written":1316413,"cfile_init":1,"dirs.queue_time_us":156,"dirs.run_cpu_time_us":340,"dirs.run_wall_time_us":1717,"drs_written":1,"lbm_read_time_us":63,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2746,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:17:53.118839 22986 maintenance_manager.cc:419] P 74e80787f39d49b4864529528064e17d: Scheduling LogGCOp(6a646a4d1f634b23b8beb277ed2c7579): free 128867446 bytes of WAL
I20260812 06:17:53.119139 22922 log_reader.cc:385] T 6a646a4d1f634b23b8beb277ed2c7579: removed 13 log segments from log reader
I20260812 06:17:53.119205 22922 log.cc:1079] T 6a646a4d1f634b23b8beb277ed2c7579 P 74e80787f39d49b4864529528064e17d: Deleting log segment in path: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465356257-22570-0/minicluster-data/ts-0-root/wals/6a646a4d1f634b23b8beb277ed2c7579/wal-000000003 (ops 12-16)
I20260812 06:17:53.119243 22922 log.cc:1079] T 6a646a4d1f634b23b8beb277ed2c7579 P 74e80787f39d49b4864529528064e17d: Deleting log segment in path: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465356257-22570-0/minicluster-data/ts-0-root/wals/6a646a4d1f634b23b8beb277ed2c7579/wal-000000004 (ops 17-20)
I20260812 06:17:53.119278 22922 log.cc:1079] T 6a646a4d1f634b23b8beb277ed2c7579 P 74e80787f39d49b4864529528064e17d: Deleting log segment in path: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465356257-22570-0/minicluster-data/ts-0-root/wals/6a646a4d1f634b23b8beb277ed2c7579/wal-000000005 (ops 21-25)
I20260812 06:17:53.119310 22922 log.cc:1079] T 6a646a4d1f634b23b8beb277ed2c7579 P 74e80787f39d49b4864529528064e17d: Deleting log segment in path: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465356257-22570-0/minicluster-data/ts-0-root/wals/6a646a4d1f634b23b8beb277ed2c7579/wal-000000006 (ops 26-30)
I20260812 06:17:53.119340 22922 log.cc:1079] T 6a646a4d1f634b23b8beb277ed2c7579 P 74e80787f39d49b4864529528064e17d: Deleting log segment in path: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465356257-22570-0/minicluster-data/ts-0-root/wals/6a646a4d1f634b23b8beb277ed2c7579/wal-000000007 (ops 31-35)
I20260812 06:17:53.119362 22922 log.cc:1079] T 6a646a4d1f634b23b8beb277ed2c7579 P 74e80787f39d49b4864529528064e17d: Deleting log segment in path: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465356257-22570-0/minicluster-data/ts-0-root/wals/6a646a4d1f634b23b8beb277ed2c7579/wal-000000008 (ops 36-40)
I20260812 06:17:53.119385 22922 log.cc:1079] T 6a646a4d1f634b23b8beb277ed2c7579 P 74e80787f39d49b4864529528064e17d: Deleting log segment in path: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465356257-22570-0/minicluster-data/ts-0-root/wals/6a646a4d1f634b23b8beb277ed2c7579/wal-000000009 (ops 41-45)
I20260812 06:17:53.119422 22922 log.cc:1079] T 6a646a4d1f634b23b8beb277ed2c7579 P 74e80787f39d49b4864529528064e17d: Deleting log segment in path: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465356257-22570-0/minicluster-data/ts-0-root/wals/6a646a4d1f634b23b8beb277ed2c7579/wal-000000010 (ops 46-50)
I20260812 06:17:53.119451 22922 log.cc:1079] T 6a646a4d1f634b23b8beb277ed2c7579 P 74e80787f39d49b4864529528064e17d: Deleting log segment in path: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465356257-22570-0/minicluster-data/ts-0-root/wals/6a646a4d1f634b23b8beb277ed2c7579/wal-000000011 (ops 51-54)
I20260812 06:17:53.119486 22922 log.cc:1079] T 6a646a4d1f634b23b8beb277ed2c7579 P 74e80787f39d49b4864529528064e17d: Deleting log segment in path: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465356257-22570-0/minicluster-data/ts-0-root/wals/6a646a4d1f634b23b8beb277ed2c7579/wal-000000012 (ops 55-59)
I20260812 06:17:53.119529 22922 log.cc:1079] T 6a646a4d1f634b23b8beb277ed2c7579 P 74e80787f39d49b4864529528064e17d: Deleting log segment in path: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465356257-22570-0/minicluster-data/ts-0-root/wals/6a646a4d1f634b23b8beb277ed2c7579/wal-000000013 (ops 60-64)
I20260812 06:17:53.119570 22922 log.cc:1079] T 6a646a4d1f634b23b8beb277ed2c7579 P 74e80787f39d49b4864529528064e17d: Deleting log segment in path: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465356257-22570-0/minicluster-data/ts-0-root/wals/6a646a4d1f634b23b8beb277ed2c7579/wal-000000014 (ops 65-68)
I20260812 06:17:53.119614 22922 log.cc:1079] T 6a646a4d1f634b23b8beb277ed2c7579 P 74e80787f39d49b4864529528064e17d: Deleting log segment in path: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465356257-22570-0/minicluster-data/ts-0-root/wals/6a646a4d1f634b23b8beb277ed2c7579/wal-000000015 (ops 69-73)
I20260812 06:17:53.152740 22922 maintenance_manager.cc:643] P 74e80787f39d49b4864529528064e17d: LogGCOp(6a646a4d1f634b23b8beb277ed2c7579) complete. Timing: real 0.034s	user 0.000s	sys 0.033s Metrics: {}
I20260812 06:17:53.153210 22986 maintenance_manager.cc:419] P 74e80787f39d49b4864529528064e17d: Scheduling UndoDeltaBlockGCOp(6a646a4d1f634b23b8beb277ed2c7579): 492 bytes on disk
I20260812 06:17:53.153828 22922 maintenance_manager.cc:643] P 74e80787f39d49b4864529528064e17d: UndoDeltaBlockGCOp(6a646a4d1f634b23b8beb277ed2c7579) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":91,"lbm_reads_lt_1ms":4}
I20260812 06:17:53.154335 22986 maintenance_manager.cc:419] P 74e80787f39d49b4864529528064e17d: Scheduling FlushDeltaMemStoresOp(6a646a4d1f634b23b8beb277ed2c7579): perf score=3.181125
I20260812 06:17:53.171164 22922 maintenance_manager.cc:643] P 74e80787f39d49b4864529528064e17d: FlushDeltaMemStoresOp(6a646a4d1f634b23b8beb277ed2c7579) complete. Timing: real 0.017s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4753,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:17:53.171761 22986 maintenance_manager.cc:419] P 74e80787f39d49b4864529528064e17d: Scheduling FlushDeltaMemStoresOp(6a646a4d1f634b23b8beb277ed2c7579): perf score=2.188937
I20260812 06:17:53.182634 22922 maintenance_manager.cc:643] P 74e80787f39d49b4864529528064e17d: FlushDeltaMemStoresOp(6a646a4d1f634b23b8beb277ed2c7579) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3973,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:53.183102 22986 maintenance_manager.cc:419] P 74e80787f39d49b4864529528064e17d: Scheduling MajorDeltaCompactionOp(6a646a4d1f634b23b8beb277ed2c7579): perf score=1.000000
I20260812 06:17:53.436693 22922 maintenance_manager.cc:643] P 74e80787f39d49b4864529528064e17d: MajorDeltaCompactionOp(6a646a4d1f634b23b8beb277ed2c7579) complete. Timing: real 0.253s	user 0.159s	sys 0.093s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979740,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":497,"lbm_read_time_us":16344,"lbm_reads_lt_1ms":774,"lbm_write_time_us":41465,"lbm_writes_lt_1ms":743,"mutex_wait_us":16,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":17280,"thread_start_us":90,"threads_started":1,"update_count":3500}
I20260812 06:17:53.437551 22986 maintenance_manager.cc:419] P 74e80787f39d49b4864529528064e17d: Scheduling FlushDeltaMemStoresOp(6a646a4d1f634b23b8beb277ed2c7579): perf score=18.063937
I20260812 06:17:53.509248 22922 maintenance_manager.cc:643] P 74e80787f39d49b4864529528064e17d: FlushDeltaMemStoresOp(6a646a4d1f634b23b8beb277ed2c7579) complete. Timing: real 0.071s	user 0.032s	sys 0.024s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":26046,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:17:53.509775 22986 maintenance_manager.cc:419] P 74e80787f39d49b4864529528064e17d: Scheduling FlushDeltaMemStoresOp(6a646a4d1f634b23b8beb277ed2c7579): perf score=2.188937
I20260812 06:17:53.520963 22922 maintenance_manager.cc:643] P 74e80787f39d49b4864529528064e17d: FlushDeltaMemStoresOp(6a646a4d1f634b23b8beb277ed2c7579) complete. Timing: real 0.011s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4113,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:17:53.521703 22986 maintenance_manager.cc:419] P 74e80787f39d49b4864529528064e17d: Scheduling MajorDeltaCompactionOp(6a646a4d1f634b23b8beb277ed2c7579): perf score=1.000000
I20260812 06:17:53.727313 22922 maintenance_manager.cc:643] P 74e80787f39d49b4864529528064e17d: MajorDeltaCompactionOp(6a646a4d1f634b23b8beb277ed2c7579) complete. Timing: real 0.205s	user 0.141s	sys 0.064s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877104,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":443,"lbm_read_time_us":13397,"lbm_reads_lt_1ms":672,"lbm_write_time_us":34950,"lbm_writes_lt_1ms":643,"mutex_wait_us":26,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":10880,"update_count":3000}
I20260812 06:17:53.729112 22986 maintenance_manager.cc:419] P 74e80787f39d49b4864529528064e17d: Scheduling FlushDeltaMemStoresOp(6a646a4d1f634b23b8beb277ed2c7579): perf score=15.087375
I20260812 06:17:53.778384 22922 maintenance_manager.cc:643] P 74e80787f39d49b4864529528064e17d: FlushDeltaMemStoresOp(6a646a4d1f634b23b8beb277ed2c7579) complete. Timing: real 0.049s	user 0.030s	sys 0.016s Metrics: {"bytes_written":16779119,"delete_count":0,"lbm_write_time_us":21776,"lbm_writes_lt_1ms":412,"reinsert_count":0,"update_count":2045}
I20260812 06:17:53.779107 22986 maintenance_manager.cc:419] P 74e80787f39d49b4864529528064e17d: Scheduling FlushDeltaMemStoresOp(6a646a4d1f634b23b8beb277ed2c7579): perf score=2.188937
I20260812 06:17:53.801132 22922 maintenance_manager.cc:643] P 74e80787f39d49b4864529528064e17d: FlushDeltaMemStoresOp(6a646a4d1f634b23b8beb277ed2c7579) complete. Timing: real 0.022s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4143687,"delete_count":0,"lbm_write_time_us":5730,"lbm_writes_lt_1ms":104,"reinsert_count":0,"update_count":505}
I20260812 06:17:53.801584 22986 maintenance_manager.cc:419] P 74e80787f39d49b4864529528064e17d: Scheduling FlushDeltaMemStoresOp(6a646a4d1f634b23b8beb277ed2c7579): perf score=2.188937
I20260812 06:17:53.811434 22922 maintenance_manager.cc:643] P 74e80787f39d49b4864529528064e17d: FlushDeltaMemStoresOp(6a646a4d1f634b23b8beb277ed2c7579) complete. Timing: real 0.010s	user 0.000s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3780,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:17:53.811913 22986 maintenance_manager.cc:419] P 74e80787f39d49b4864529528064e17d: Scheduling MajorDeltaCompactionOp(6a646a4d1f634b23b8beb277ed2c7579): perf score=1.000000
I20260812 06:17:54.095978 22922 maintenance_manager.cc:643] P 74e80787f39d49b4864529528064e17d: MajorDeltaCompactionOp(6a646a4d1f634b23b8beb277ed2c7579) complete. Timing: real 0.284s	user 0.139s	sys 0.076s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877211,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":195,"lbm_read_time_us":15714,"lbm_reads_lt_1ms":673,"lbm_write_time_us":37233,"lbm_writes_lt_1ms":643,"mutex_wait_us":73,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":5760,"update_count":3000}
I20260812 06:17:54.096832 22986 maintenance_manager.cc:419] P 74e80787f39d49b4864529528064e17d: Scheduling FlushDeltaMemStoresOp(6a646a4d1f634b23b8beb277ed2c7579): perf score=19.056125
I20260812 06:17:54.193514 22922 maintenance_manager.cc:643] P 74e80787f39d49b4864529528064e17d: FlushDeltaMemStoresOp(6a646a4d1f634b23b8beb277ed2c7579) complete. Timing: real 0.096s	user 0.038s	sys 0.019s Metrics: {"bytes_written":20922558,"delete_count":0,"lbm_write_time_us":25410,"lbm_writes_lt_1ms":513,"reinsert_count":0,"update_count":2550}
I20260812 06:17:54.194242 22986 maintenance_manager.cc:419] P 74e80787f39d49b4864529528064e17d: Scheduling FlushDeltaMemStoresOp(6a646a4d1f634b23b8beb277ed2c7579): perf score=6.157687
I20260812 06:17:54.288638 22922 maintenance_manager.cc:643] P 74e80787f39d49b4864529528064e17d: FlushDeltaMemStoresOp(6a646a4d1f634b23b8beb277ed2c7579) complete. Timing: real 0.094s	user 0.019s	sys 0.008s Metrics: {"bytes_written":7794836,"delete_count":0,"lbm_write_time_us":11178,"lbm_writes_lt_1ms":193,"reinsert_count":0,"update_count":950}
I20260812 06:17:54.289309 22986 maintenance_manager.cc:419] P 74e80787f39d49b4864529528064e17d: Scheduling FlushDeltaMemStoresOp(6a646a4d1f634b23b8beb277ed2c7579): perf score=6.157687
I20260812 06:17:54.384097 22922 maintenance_manager.cc:643] P 74e80787f39d49b4864529528064e17d: FlushDeltaMemStoresOp(6a646a4d1f634b23b8beb277ed2c7579) complete. Timing: real 0.095s	user 0.003s	sys 0.017s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":8420,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:17:54.384819 22986 maintenance_manager.cc:419] P 74e80787f39d49b4864529528064e17d: Scheduling FlushDeltaMemStoresOp(6a646a4d1f634b23b8beb277ed2c7579): perf score=7.149875
I20260812 06:17:54.487486 22922 maintenance_manager.cc:643] P 74e80787f39d49b4864529528064e17d: FlushDeltaMemStoresOp(6a646a4d1f634b23b8beb277ed2c7579) complete. Timing: real 0.102s	user 0.006s	sys 0.016s Metrics: {"bytes_written":8615323,"delete_count":0,"lbm_write_time_us":10394,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:17:54.488564 22986 maintenance_manager.cc:419] P 74e80787f39d49b4864529528064e17d: Scheduling FlushDeltaMemStoresOp(6a646a4d1f634b23b8beb277ed2c7579): perf score=8.142062
I20260812 06:17:54.591346 22922 maintenance_manager.cc:643] P 74e80787f39d49b4864529528064e17d: FlushDeltaMemStoresOp(6a646a4d1f634b23b8beb277ed2c7579) complete. Timing: real 0.103s	user 0.014s	sys 0.009s Metrics: {"bytes_written":9476827,"delete_count":0,"lbm_write_time_us":9948,"lbm_writes_lt_1ms":234,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":1155}
I20260812 06:17:54.592233 22986 maintenance_manager.cc:419] P 74e80787f39d49b4864529528064e17d: Scheduling FlushDeltaMemStoresOp(6a646a4d1f634b23b8beb277ed2c7579): perf score=9.134250
I20260812 06:17:54.695243 22922 maintenance_manager.cc:643] P 74e80787f39d49b4864529528064e17d: FlushDeltaMemStoresOp(6a646a4d1f634b23b8beb277ed2c7579) complete. Timing: real 0.103s	user 0.016s	sys 0.013s Metrics: {"bytes_written":10625503,"delete_count":0,"lbm_write_time_us":12569,"lbm_writes_lt_1ms":262,"reinsert_count":0,"update_count":1295}
I20260812 06:17:54.696130 22986 maintenance_manager.cc:419] P 74e80787f39d49b4864529528064e17d: Scheduling FlushDeltaMemStoresOp(6a646a4d1f634b23b8beb277ed2c7579): perf score=6.157687
I20260812 06:17:54.795501 22922 maintenance_manager.cc:643] P 74e80787f39d49b4864529528064e17d: FlushDeltaMemStoresOp(6a646a4d1f634b23b8beb277ed2c7579) complete. Timing: real 0.099s	user 0.022s	sys 0.005s Metrics: {"bytes_written":8205079,"delete_count":0,"lbm_write_time_us":11523,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:17:54.796002 22986 maintenance_manager.cc:419] P 74e80787f39d49b4864529528064e17d: Scheduling FlushDeltaMemStoresOp(6a646a4d1f634b23b8beb277ed2c7579): perf score=7.149875
I20260812 06:17:54.897680 22922 maintenance_manager.cc:643] P 74e80787f39d49b4864529528064e17d: FlushDeltaMemStoresOp(6a646a4d1f634b23b8beb277ed2c7579) complete. Timing: real 0.101s	user 0.006s	sys 0.012s Metrics: {"bytes_written":8615323,"delete_count":0,"lbm_write_time_us":8097,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:17:54.898288 22986 maintenance_manager.cc:419] P 74e80787f39d49b4864529528064e17d: Scheduling FlushDeltaMemStoresOp(6a646a4d1f634b23b8beb277ed2c7579): perf score=9.134250
I20260812 06:17:55.000147 22922 maintenance_manager.cc:643] P 74e80787f39d49b4864529528064e17d: FlushDeltaMemStoresOp(6a646a4d1f634b23b8beb277ed2c7579) complete. Timing: real 0.102s	user 0.034s	sys 0.000s Metrics: {"bytes_written":10994718,"delete_count":0,"lbm_write_time_us":14469,"lbm_writes_lt_1ms":271,"reinsert_count":0,"update_count":1340}
I20260812 06:17:55.000699 22986 maintenance_manager.cc:419] P 74e80787f39d49b4864529528064e17d: Scheduling FlushDeltaMemStoresOp(6a646a4d1f634b23b8beb277ed2c7579): perf score=5.165500
I20260812 06:17:55.103336 22922 maintenance_manager.cc:643] P 74e80787f39d49b4864529528064e17d: FlushDeltaMemStoresOp(6a646a4d1f634b23b8beb277ed2c7579) complete. Timing: real 0.102s	user 0.011s	sys 0.003s Metrics: {"bytes_written":6359004,"delete_count":0,"lbm_write_time_us":6250,"lbm_writes_lt_1ms":158,"reinsert_count":0,"update_count":775}
I20260812 06:17:55.103955 22986 maintenance_manager.cc:419] P 74e80787f39d49b4864529528064e17d: Scheduling FlushDeltaMemStoresOp(6a646a4d1f634b23b8beb277ed2c7579): perf score=9.134250
I20260812 06:17:55.207067 22922 maintenance_manager.cc:643] P 74e80787f39d49b4864529528064e17d: FlushDeltaMemStoresOp(6a646a4d1f634b23b8beb277ed2c7579) complete. Timing: real 0.103s	user 0.014s	sys 0.013s Metrics: {"bytes_written":10953704,"delete_count":0,"lbm_write_time_us":12247,"lbm_writes_lt_1ms":270,"reinsert_count":0,"update_count":1335}
I20260812 06:17:55.207641 22986 maintenance_manager.cc:419] P 74e80787f39d49b4864529528064e17d: Scheduling FlushDeltaMemStoresOp(6a646a4d1f634b23b8beb277ed2c7579): perf score=6.157687
I20260812 06:17:55.307744 22922 maintenance_manager.cc:643] P 74e80787f39d49b4864529528064e17d: FlushDeltaMemStoresOp(6a646a4d1f634b23b8beb277ed2c7579) complete. Timing: real 0.100s	user 0.019s	sys 0.003s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":9530,"lbm_writes_lt_1ms":203,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":1000}
I20260812 06:17:55.308818 22986 maintenance_manager.cc:419] P 74e80787f39d49b4864529528064e17d: Scheduling FlushDeltaMemStoresOp(6a646a4d1f634b23b8beb277ed2c7579): perf score=7.149875
I20260812 06:17:55.409433 22922 maintenance_manager.cc:643] P 74e80787f39d49b4864529528064e17d: FlushDeltaMemStoresOp(6a646a4d1f634b23b8beb277ed2c7579) complete. Timing: real 0.100s	user 0.023s	sys 0.004s Metrics: {"bytes_written":8697368,"delete_count":0,"lbm_write_time_us":11427,"lbm_writes_lt_1ms":215,"reinsert_count":0,"update_count":1060}
I20260812 06:17:55.410281 22986 maintenance_manager.cc:419] P 74e80787f39d49b4864529528064e17d: Scheduling FlushDeltaMemStoresOp(6a646a4d1f634b23b8beb277ed2c7579): perf score=10.126437
I20260812 06:17:55.511540 22922 maintenance_manager.cc:643] P 74e80787f39d49b4864529528064e17d: FlushDeltaMemStoresOp(6a646a4d1f634b23b8beb277ed2c7579) complete. Timing: real 0.101s	user 0.020s	sys 0.011s Metrics: {"bytes_written":11815211,"delete_count":0,"lbm_write_time_us":14234,"lbm_writes_lt_1ms":291,"reinsert_count":0,"update_count":1440}
I20260812 06:17:55.512494 22986 maintenance_manager.cc:419] P 74e80787f39d49b4864529528064e17d: Scheduling FlushDeltaMemStoresOp(6a646a4d1f634b23b8beb277ed2c7579): perf score=6.157687
I20260812 06:17:55.614818 22922 maintenance_manager.cc:643] P 74e80787f39d49b4864529528064e17d: FlushDeltaMemStoresOp(6a646a4d1f634b23b8beb277ed2c7579) complete. Timing: real 0.102s	user 0.014s	sys 0.009s Metrics: {"bytes_written":8205077,"delete_count":0,"lbm_write_time_us":9745,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:17:55.615803 22986 maintenance_manager.cc:419] P 74e80787f39d49b4864529528064e17d: Scheduling FlushDeltaMemStoresOp(6a646a4d1f634b23b8beb277ed2c7579): perf score=6.157687
I20260812 06:17:55.716667 22922 maintenance_manager.cc:643] P 74e80787f39d49b4864529528064e17d: FlushDeltaMemStoresOp(6a646a4d1f634b23b8beb277ed2c7579) complete. Timing: real 0.101s	user 0.021s	sys 0.004s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":10584,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:17:55.717648 22986 maintenance_manager.cc:419] P 74e80787f39d49b4864529528064e17d: Scheduling FlushDeltaMemStoresOp(6a646a4d1f634b23b8beb277ed2c7579): perf score=10.126437
W20260812 06:17:55.818902 23006 log.cc:927] Time spent T 6a646a4d1f634b23b8beb277ed2c7579 P 74e80787f39d49b4864529528064e17d: Append to log took a long time: real 0.072s	user 0.000s	sys 0.000s
I20260812 06:17:55.935571 22922 maintenance_manager.cc:643] P 74e80787f39d49b4864529528064e17d: FlushDeltaMemStoresOp(6a646a4d1f634b23b8beb277ed2c7579) complete. Timing: real 0.218s	user 0.011s	sys 0.019s Metrics: {"bytes_written":11528036,"delete_count":0,"lbm_write_time_us":96509,"lbm_writes_10-100_ms":1,"lbm_writes_lt_1ms":283,"reinsert_count":0,"update_count":1405}
I20260812 06:17:55.936381 22986 maintenance_manager.cc:419] P 74e80787f39d49b4864529528064e17d: Scheduling FlushDeltaMemStoresOp(6a646a4d1f634b23b8beb277ed2c7579): perf score=9.134250
I20260812 06:17:56.041426 22922 maintenance_manager.cc:643] P 74e80787f39d49b4864529528064e17d: FlushDeltaMemStoresOp(6a646a4d1f634b23b8beb277ed2c7579) complete. Timing: real 0.105s	user 0.019s	sys 0.012s Metrics: {"bytes_written":11322919,"delete_count":0,"lbm_write_time_us":15084,"lbm_writes_lt_1ms":279,"reinsert_count":0,"update_count":1380}
I20260812 06:17:56.042308 22986 maintenance_manager.cc:419] P 74e80787f39d49b4864529528064e17d: Scheduling FlushDeltaMemStoresOp(6a646a4d1f634b23b8beb277ed2c7579): perf score=8.142062
I20260812 06:17:56.145352 22922 maintenance_manager.cc:643] P 74e80787f39d49b4864529528064e17d: FlushDeltaMemStoresOp(6a646a4d1f634b23b8beb277ed2c7579) complete. Timing: real 0.103s	user 0.023s	sys 0.008s Metrics: {"bytes_written":9969125,"delete_count":0,"lbm_write_time_us":13277,"lbm_writes_lt_1ms":246,"reinsert_count":0,"update_count":1215}
I20260812 06:17:56.146734 22986 maintenance_manager.cc:419] P 74e80787f39d49b4864529528064e17d: Scheduling FlushDeltaMemStoresOp(6a646a4d1f634b23b8beb277ed2c7579): perf score=6.157687
I20260812 06:17:56.219950 22570 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.872s	user 1.790s	sys 0.142s
I20260812 06:17:56.244385 22922 maintenance_manager.cc:643] P 74e80787f39d49b4864529528064e17d: FlushDeltaMemStoresOp(6a646a4d1f634b23b8beb277ed2c7579) complete. Timing: real 0.097s	user 0.020s	sys 0.004s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":10118,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:17:56.245971 22986 maintenance_manager.cc:419] P 74e80787f39d49b4864529528064e17d: Scheduling FlushDeltaMemStoresOp(6a646a4d1f634b23b8beb277ed2c7579): perf score=6.157687
I20260812 06:17:56.346295 22922 maintenance_manager.cc:643] P 74e80787f39d49b4864529528064e17d: FlushDeltaMemStoresOp(6a646a4d1f634b23b8beb277ed2c7579) complete. Timing: real 0.100s	user 0.008s	sys 0.014s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":10692,"lbm_writes_lt_1ms":203,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":1000}
I20260812 06:17:56.347198 22986 maintenance_manager.cc:419] P 74e80787f39d49b4864529528064e17d: Scheduling FlushMRSOp(6a646a4d1f634b23b8beb277ed2c7579): perf score=1.195565
I20260812 06:17:56.445614 22922 maintenance_manager.cc:643] P 74e80787f39d49b4864529528064e17d: FlushMRSOp(6a646a4d1f634b23b8beb277ed2c7579) complete. Timing: real 0.098s	user 0.037s	sys 0.001s Metrics: {"bytes_written":2627805,"cfile_init":1,"dirs.queue_time_us":250,"dirs.run_cpu_time_us":279,"dirs.run_wall_time_us":65144,"drs_written":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4,"lbm_write_time_us":4121,"lbm_writes_lt_1ms":44,"peak_mem_usage":0,"rows_written":64,"thread_start_us":108,"threads_started":1}
I20260812 06:17:56.446696 22986 maintenance_manager.cc:419] P 74e80787f39d49b4864529528064e17d: Scheduling LogGCOp(6a646a4d1f634b23b8beb277ed2c7579): free 253578136 bytes of WAL
I20260812 06:17:56.447091 22922 log_reader.cc:385] T 6a646a4d1f634b23b8beb277ed2c7579: removed 25 log segments from log reader
I20260812 06:17:56.447162 22922 log.cc:1079] T 6a646a4d1f634b23b8beb277ed2c7579 P 74e80787f39d49b4864529528064e17d: Deleting log segment in path: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465356257-22570-0/minicluster-data/ts-0-root/wals/6a646a4d1f634b23b8beb277ed2c7579/wal-000000016 (ops 74-78)
I20260812 06:17:56.447289 22922 log.cc:1079] T 6a646a4d1f634b23b8beb277ed2c7579 P 74e80787f39d49b4864529528064e17d: Deleting log segment in path: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465356257-22570-0/minicluster-data/ts-0-root/wals/6a646a4d1f634b23b8beb277ed2c7579/wal-000000017 (ops 79-82)
I20260812 06:17:56.447340 22922 log.cc:1079] T 6a646a4d1f634b23b8beb277ed2c7579 P 74e80787f39d49b4864529528064e17d: Deleting log segment in path: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465356257-22570-0/minicluster-data/ts-0-root/wals/6a646a4d1f634b23b8beb277ed2c7579/wal-000000018 (ops 83-87)
I20260812 06:17:56.447418 22922 log.cc:1079] T 6a646a4d1f634b23b8beb277ed2c7579 P 74e80787f39d49b4864529528064e17d: Deleting log segment in path: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465356257-22570-0/minicluster-data/ts-0-root/wals/6a646a4d1f634b23b8beb277ed2c7579/wal-000000019 (ops 88-92)
I20260812 06:17:56.447467 22922 log.cc:1079] T 6a646a4d1f634b23b8beb277ed2c7579 P 74e80787f39d49b4864529528064e17d: Deleting log segment in path: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465356257-22570-0/minicluster-data/ts-0-root/wals/6a646a4d1f634b23b8beb277ed2c7579/wal-000000020 (ops 93-97)
I20260812 06:17:56.447508 22922 log.cc:1079] T 6a646a4d1f634b23b8beb277ed2c7579 P 74e80787f39d49b4864529528064e17d: Deleting log segment in path: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465356257-22570-0/minicluster-data/ts-0-root/wals/6a646a4d1f634b23b8beb277ed2c7579/wal-000000021 (ops 98-102)
I20260812 06:17:56.447551 22922 log.cc:1079] T 6a646a4d1f634b23b8beb277ed2c7579 P 74e80787f39d49b4864529528064e17d: Deleting log segment in path: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465356257-22570-0/minicluster-data/ts-0-root/wals/6a646a4d1f634b23b8beb277ed2c7579/wal-000000022 (ops 103-106)
I20260812 06:17:56.447594 22922 log.cc:1079] T 6a646a4d1f634b23b8beb277ed2c7579 P 74e80787f39d49b4864529528064e17d: Deleting log segment in path: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465356257-22570-0/minicluster-data/ts-0-root/wals/6a646a4d1f634b23b8beb277ed2c7579/wal-000000023 (ops 107-111)
I20260812 06:17:56.447638 22922 log.cc:1079] T 6a646a4d1f634b23b8beb277ed2c7579 P 74e80787f39d49b4864529528064e17d: Deleting log segment in path: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465356257-22570-0/minicluster-data/ts-0-root/wals/6a646a4d1f634b23b8beb277ed2c7579/wal-000000024 (ops 112-116)
I20260812 06:17:56.447706 22922 log.cc:1079] T 6a646a4d1f634b23b8beb277ed2c7579 P 74e80787f39d49b4864529528064e17d: Deleting log segment in path: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465356257-22570-0/minicluster-data/ts-0-root/wals/6a646a4d1f634b23b8beb277ed2c7579/wal-000000025 (ops 117-121)
I20260812 06:17:56.447753 22922 log.cc:1079] T 6a646a4d1f634b23b8beb277ed2c7579 P 74e80787f39d49b4864529528064e17d: Deleting log segment in path: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465356257-22570-0/minicluster-data/ts-0-root/wals/6a646a4d1f634b23b8beb277ed2c7579/wal-000000026 (ops 122-126)
I20260812 06:17:56.447796 22922 log.cc:1079] T 6a646a4d1f634b23b8beb277ed2c7579 P 74e80787f39d49b4864529528064e17d: Deleting log segment in path: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465356257-22570-0/minicluster-data/ts-0-root/wals/6a646a4d1f634b23b8beb277ed2c7579/wal-000000027 (ops 127-131)
I20260812 06:17:56.447839 22922 log.cc:1079] T 6a646a4d1f634b23b8beb277ed2c7579 P 74e80787f39d49b4864529528064e17d: Deleting log segment in path: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465356257-22570-0/minicluster-data/ts-0-root/wals/6a646a4d1f634b23b8beb277ed2c7579/wal-000000028 (ops 132-136)
I20260812 06:17:56.447882 22922 log.cc:1079] T 6a646a4d1f634b23b8beb277ed2c7579 P 74e80787f39d49b4864529528064e17d: Deleting log segment in path: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465356257-22570-0/minicluster-data/ts-0-root/wals/6a646a4d1f634b23b8beb277ed2c7579/wal-000000029 (ops 137-141)
I20260812 06:17:56.447925 22922 log.cc:1079] T 6a646a4d1f634b23b8beb277ed2c7579 P 74e80787f39d49b4864529528064e17d: Deleting log segment in path: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465356257-22570-0/minicluster-data/ts-0-root/wals/6a646a4d1f634b23b8beb277ed2c7579/wal-000000030 (ops 142-146)
I20260812 06:17:56.447995 22922 log.cc:1079] T 6a646a4d1f634b23b8beb277ed2c7579 P 74e80787f39d49b4864529528064e17d: Deleting log segment in path: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465356257-22570-0/minicluster-data/ts-0-root/wals/6a646a4d1f634b23b8beb277ed2c7579/wal-000000031 (ops 147-151)
I20260812 06:17:56.448043 22922 log.cc:1079] T 6a646a4d1f634b23b8beb277ed2c7579 P 74e80787f39d49b4864529528064e17d: Deleting log segment in path: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465356257-22570-0/minicluster-data/ts-0-root/wals/6a646a4d1f634b23b8beb277ed2c7579/wal-000000032 (ops 152-156)
I20260812 06:17:56.448132 22922 log.cc:1079] T 6a646a4d1f634b23b8beb277ed2c7579 P 74e80787f39d49b4864529528064e17d: Deleting log segment in path: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465356257-22570-0/minicluster-data/ts-0-root/wals/6a646a4d1f634b23b8beb277ed2c7579/wal-000000033 (ops 157-161)
I20260812 06:17:56.448177 22922 log.cc:1079] T 6a646a4d1f634b23b8beb277ed2c7579 P 74e80787f39d49b4864529528064e17d: Deleting log segment in path: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465356257-22570-0/minicluster-data/ts-0-root/wals/6a646a4d1f634b23b8beb277ed2c7579/wal-000000034 (ops 162-166)
I20260812 06:17:56.448251 22922 log.cc:1079] T 6a646a4d1f634b23b8beb277ed2c7579 P 74e80787f39d49b4864529528064e17d: Deleting log segment in path: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465356257-22570-0/minicluster-data/ts-0-root/wals/6a646a4d1f634b23b8beb277ed2c7579/wal-000000035 (ops 167-170)
I20260812 06:17:56.448298 22922 log.cc:1079] T 6a646a4d1f634b23b8beb277ed2c7579 P 74e80787f39d49b4864529528064e17d: Deleting log segment in path: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465356257-22570-0/minicluster-data/ts-0-root/wals/6a646a4d1f634b23b8beb277ed2c7579/wal-000000036 (ops 171-175)
I20260812 06:17:56.448341 22922 log.cc:1079] T 6a646a4d1f634b23b8beb277ed2c7579 P 74e80787f39d49b4864529528064e17d: Deleting log segment in path: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465356257-22570-0/minicluster-data/ts-0-root/wals/6a646a4d1f634b23b8beb277ed2c7579/wal-000000037 (ops 176-180)
I20260812 06:17:56.448381 22922 log.cc:1079] T 6a646a4d1f634b23b8beb277ed2c7579 P 74e80787f39d49b4864529528064e17d: Deleting log segment in path: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465356257-22570-0/minicluster-data/ts-0-root/wals/6a646a4d1f634b23b8beb277ed2c7579/wal-000000038 (ops 181-185)
I20260812 06:17:56.448426 22922 log.cc:1079] T 6a646a4d1f634b23b8beb277ed2c7579 P 74e80787f39d49b4864529528064e17d: Deleting log segment in path: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465356257-22570-0/minicluster-data/ts-0-root/wals/6a646a4d1f634b23b8beb277ed2c7579/wal-000000039 (ops 186-190)
I20260812 06:17:56.448472 22922 log.cc:1079] T 6a646a4d1f634b23b8beb277ed2c7579 P 74e80787f39d49b4864529528064e17d: Deleting log segment in path: /tmp/dist-test-task4e1StB/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515465356257-22570-0/minicluster-data/ts-0-root/wals/6a646a4d1f634b23b8beb277ed2c7579/wal-000000040 (ops 191-195)
I20260812 06:17:56.501583 22922 maintenance_manager.cc:643] P 74e80787f39d49b4864529528064e17d: LogGCOp(6a646a4d1f634b23b8beb277ed2c7579) complete. Timing: real 0.055s	user 0.000s	sys 0.053s Metrics: {}
I20260812 06:17:56.502187 22986 maintenance_manager.cc:419] P 74e80787f39d49b4864529528064e17d: Scheduling MajorDeltaCompactionOp(6a646a4d1f634b23b8beb277ed2c7579): perf score=1.000000
W20260812 06:17:56.737495 22570 scanner-internal.cc:458] Time spent opening tablet: real 0.517s	user 0.000s	sys 0.001s
I20260812 06:17:56.739753 22570 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.519s	user 0.000s	sys 0.001s
I20260812 06:17:56.740350 22570 tablet_server.cc:179] TabletServer@127.22.10.129:0 shutting down...
I20260812 06:17:57.841661 22922 maintenance_manager.cc:643] P 74e80787f39d49b4864529528064e17d: MajorDeltaCompactionOp(6a646a4d1f634b23b8beb277ed2c7579) complete. Timing: real 1.339s	user 0.720s	sys 0.619s Metrics: {"cfile_cache_hit":2090,"cfile_cache_hit_bytes":85712990,"cfile_cache_miss":2961,"cfile_cache_miss_bytes":123672587,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":21,"delta_iterators_relevant":21,"dirs.queue_time_us":1559,"lbm_read_time_us":57174,"lbm_reads_lt_1ms":2997,"lbm_write_time_us":285474,"lbm_writes_lt_1ms":5047,"peak_mem_usage":622311640,"reinsert_count":0,"spinlock_wait_cycles":32000,"thread_start_us":527,"threads_started":7,"update_count":25000,"wal-append.queue_time_us":237}
I20260812 06:17:57.842381 22570 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:17:57.842576 22570 tablet_replica.cc:333] T 6a646a4d1f634b23b8beb277ed2c7579 P 74e80787f39d49b4864529528064e17d: stopping tablet replica
I20260812 06:17:57.842707 22570 raft_consensus.cc:2243] T 6a646a4d1f634b23b8beb277ed2c7579 P 74e80787f39d49b4864529528064e17d [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:57.842882 22570 raft_consensus.cc:2272] T 6a646a4d1f634b23b8beb277ed2c7579 P 74e80787f39d49b4864529528064e17d [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:57.856489 22570 tablet_server.cc:196] TabletServer@127.22.10.129:0 shutdown complete.
I20260812 06:17:58.626050 22570 master.cc:562] Master@127.22.10.190:33235 shutting down...
I20260812 06:17:58.630481 22570 raft_consensus.cc:2243] T 00000000000000000000000000000000 P dc521b9d88e345d19960c5eb8c778d5f [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:17:58.630681 22570 raft_consensus.cc:2272] T 00000000000000000000000000000000 P dc521b9d88e345d19960c5eb8c778d5f [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:17:58.630733 22570 tablet_replica.cc:333] T 00000000000000000000000000000000 P dc521b9d88e345d19960c5eb8c778d5f: stopping tablet replica
I20260812 06:17:58.643515 22570 master.cc:584] Master@127.22.10.190:33235 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (7598 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (13365 ms total)

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