[==========] 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:18:08.807960 25591 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.24.253.254:38683
I20260812 06:18:08.808934 25591 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:18:08.809492 25591 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:08.816697 25600 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:18:08.816716 25597 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:18:08.816888 25591 server_base.cc:1061] running on GCE node
W20260812 06:18:08.817030 25598 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:18:08.817553 25591 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:08.817648 25591 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:18:08.817677 25591 hybrid_clock.cc:648] HybridClock initialized: now 1786515488817676 us; error 0 us; skew 500 ppm
I20260812 06:18:08.819757 25591 webserver.cc:533] Webserver started at http://127.24.253.254:35353/ using document root <none> and password file <none>
I20260812 06:18:08.820382 25591 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:08.820441 25591 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:08.820681 25591 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:08.822374 25591 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515488796982-25591-0/minicluster-data/master-0-root/instance:
uuid: "6f7bd8e0cc064a50b87a6defa014d072"
format_stamp: "Formatted at 2026-08-12 06:18:08 on dist-test-slave-mvvj"
I20260812 06:18:08.826223 25591 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.005s	sys 0.000s
I20260812 06:18:08.828581 25605 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:18:08.829734 25591 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:08.829885 25591 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515488796982-25591-0/minicluster-data/master-0-root
uuid: "6f7bd8e0cc064a50b87a6defa014d072"
format_stamp: "Formatted at 2026-08-12 06:18:08 on dist-test-slave-mvvj"
I20260812 06:18:08.830003 25591 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515488796982-25591-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515488796982-25591-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515488796982-25591-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:18:08.857630 25591 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:08.858414 25591 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:18:08.858639 25591 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:08.867657 25591 rpc_server.cc:307] RPC server started. Bound to: 127.24.253.254:38683
I20260812 06:18:08.867671 25665 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.24.253.254:38683 every 8 connection(s)
I20260812 06:18:08.870239 25666 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:18:08.876107 25666 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 6f7bd8e0cc064a50b87a6defa014d072: Bootstrap starting.
I20260812 06:18:08.879340 25666 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 6f7bd8e0cc064a50b87a6defa014d072: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:08.880393 25666 log.cc:826] T 00000000000000000000000000000000 P 6f7bd8e0cc064a50b87a6defa014d072: Log is configured to *not* fsync() on all Append() calls
I20260812 06:18:08.882203 25666 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 6f7bd8e0cc064a50b87a6defa014d072: No bootstrap required, opened a new log
I20260812 06:18:08.885144 25666 raft_consensus.cc:359] T 00000000000000000000000000000000 P 6f7bd8e0cc064a50b87a6defa014d072 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6f7bd8e0cc064a50b87a6defa014d072" member_type: VOTER }
I20260812 06:18:08.885317 25666 raft_consensus.cc:385] T 00000000000000000000000000000000 P 6f7bd8e0cc064a50b87a6defa014d072 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:08.885402 25666 raft_consensus.cc:740] T 00000000000000000000000000000000 P 6f7bd8e0cc064a50b87a6defa014d072 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 6f7bd8e0cc064a50b87a6defa014d072, State: Initialized, Role: FOLLOWER
I20260812 06:18:08.886047 25666 consensus_queue.cc:260] T 00000000000000000000000000000000 P 6f7bd8e0cc064a50b87a6defa014d072 [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: "6f7bd8e0cc064a50b87a6defa014d072" member_type: VOTER }
I20260812 06:18:08.886224 25666 raft_consensus.cc:399] T 00000000000000000000000000000000 P 6f7bd8e0cc064a50b87a6defa014d072 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:08.886337 25666 raft_consensus.cc:493] T 00000000000000000000000000000000 P 6f7bd8e0cc064a50b87a6defa014d072 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:08.886488 25666 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 6f7bd8e0cc064a50b87a6defa014d072 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:08.887383 25666 raft_consensus.cc:515] T 00000000000000000000000000000000 P 6f7bd8e0cc064a50b87a6defa014d072 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6f7bd8e0cc064a50b87a6defa014d072" member_type: VOTER }
I20260812 06:18:08.887884 25666 leader_election.cc:304] T 00000000000000000000000000000000 P 6f7bd8e0cc064a50b87a6defa014d072 [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: 6f7bd8e0cc064a50b87a6defa014d072; no voters: 
I20260812 06:18:08.888242 25666 leader_election.cc:290] T 00000000000000000000000000000000 P 6f7bd8e0cc064a50b87a6defa014d072 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:08.888466 25669 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 6f7bd8e0cc064a50b87a6defa014d072 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:08.888773 25669 raft_consensus.cc:697] T 00000000000000000000000000000000 P 6f7bd8e0cc064a50b87a6defa014d072 [term 1 LEADER]: Becoming Leader. State: Replica: 6f7bd8e0cc064a50b87a6defa014d072, State: Running, Role: LEADER
I20260812 06:18:08.889225 25669 consensus_queue.cc:237] T 00000000000000000000000000000000 P 6f7bd8e0cc064a50b87a6defa014d072 [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: "6f7bd8e0cc064a50b87a6defa014d072" member_type: VOTER }
I20260812 06:18:08.889307 25666 sys_catalog.cc:565] T 00000000000000000000000000000000 P 6f7bd8e0cc064a50b87a6defa014d072 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:08.891348 25670 sys_catalog.cc:455] T 00000000000000000000000000000000 P 6f7bd8e0cc064a50b87a6defa014d072 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "6f7bd8e0cc064a50b87a6defa014d072" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6f7bd8e0cc064a50b87a6defa014d072" member_type: VOTER } }
I20260812 06:18:08.891494 25670 sys_catalog.cc:458] T 00000000000000000000000000000000 P 6f7bd8e0cc064a50b87a6defa014d072 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:08.891736 25591 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:08.891919 25683 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:08.891848 25671 sys_catalog.cc:455] T 00000000000000000000000000000000 P 6f7bd8e0cc064a50b87a6defa014d072 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 6f7bd8e0cc064a50b87a6defa014d072. Latest consensus state: current_term: 1 leader_uuid: "6f7bd8e0cc064a50b87a6defa014d072" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6f7bd8e0cc064a50b87a6defa014d072" member_type: VOTER } }
I20260812 06:18:08.892007 25671 sys_catalog.cc:458] T 00000000000000000000000000000000 P 6f7bd8e0cc064a50b87a6defa014d072 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:08.894629 25683 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:08.900245 25683 catalog_manager.cc:1383] Generated new cluster ID: fbefbd0dffd24cfa8ddc847b5fa5c209
I20260812 06:18:08.900344 25683 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:08.920843 25683 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:08.921823 25683 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:08.935588 25683 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 6f7bd8e0cc064a50b87a6defa014d072: Generated new TSK 0
I20260812 06:18:08.936343 25683 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:08.956907 25591 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:08.960338 25691 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:18:08.960359 25690 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:18:08.960553 25694 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:18:08.960597 25591 server_base.cc:1061] running on GCE node
I20260812 06:18:08.960754 25591 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:08.960836 25591 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:18:08.960891 25591 hybrid_clock.cc:648] HybridClock initialized: now 1786515488960890 us; error 0 us; skew 500 ppm
I20260812 06:18:08.962050 25591 webserver.cc:533] Webserver started at http://127.24.253.193:40639/ using document root <none> and password file <none>
I20260812 06:18:08.962244 25591 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:08.962319 25591 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:08.962404 25591 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:08.962802 25591 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515488796982-25591-0/minicluster-data/ts-0-root/instance:
uuid: "54fbcfe96d6d47bb930c301ac4fb0790"
format_stamp: "Formatted at 2026-08-12 06:18:08 on dist-test-slave-mvvj"
I20260812 06:18:08.964668 25591 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:08.965803 25700 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:18:08.966085 25591 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:08.966168 25591 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515488796982-25591-0/minicluster-data/ts-0-root
uuid: "54fbcfe96d6d47bb930c301ac4fb0790"
format_stamp: "Formatted at 2026-08-12 06:18:08 on dist-test-slave-mvvj"
I20260812 06:18:08.966267 25591 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515488796982-25591-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515488796982-25591-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515488796982-25591-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:18:08.981647 25591 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:08.982218 25591 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:08.982767 25591 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:08.983675 25591 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:08.983729 25591 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:08.983799 25591 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:08.983899 25591 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:08.991079 25591 rpc_server.cc:307] RPC server started. Bound to: 127.24.253.193:34033
I20260812 06:18:08.991146 25774 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.24.253.193:34033 every 8 connection(s)
I20260812 06:18:09.005581 25775 heartbeater.cc:344] Connected to a master server at 127.24.253.254:38683
I20260812 06:18:09.005859 25775 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:09.006358 25775 heartbeater.cc:507] Master 127.24.253.254:38683 requested a full tablet report, sending...
I20260812 06:18:09.008028 25626 ts_manager.cc:194] Registered new tserver with Master: 54fbcfe96d6d47bb930c301ac4fb0790 (127.24.253.193:34033)
I20260812 06:18:09.008818 25591 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.01694121s
I20260812 06:18:09.009543 25626 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:46954
I20260812 06:18:09.019591 25626 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:46968:
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:18:09.035233 25735 tablet_service.cc:1511] Processing CreateTablet for tablet eb19157d8268428fa9b9527ab63a9908 (DEFAULT_TABLE table=heavy-update-compaction-test [id=7ec6c24cf5dd42b2bf9adfc22bb48130]), partition=
I20260812 06:18:09.035779 25735 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet eb19157d8268428fa9b9527ab63a9908. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:09.038110 25790 tablet_bootstrap.cc:492] T eb19157d8268428fa9b9527ab63a9908 P 54fbcfe96d6d47bb930c301ac4fb0790: Bootstrap starting.
I20260812 06:18:09.039423 25790 tablet_bootstrap.cc:654] T eb19157d8268428fa9b9527ab63a9908 P 54fbcfe96d6d47bb930c301ac4fb0790: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:09.040683 25790 tablet_bootstrap.cc:492] T eb19157d8268428fa9b9527ab63a9908 P 54fbcfe96d6d47bb930c301ac4fb0790: No bootstrap required, opened a new log
I20260812 06:18:09.040808 25790 ts_tablet_manager.cc:1403] T eb19157d8268428fa9b9527ab63a9908 P 54fbcfe96d6d47bb930c301ac4fb0790: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:18:09.041293 25790 raft_consensus.cc:359] T eb19157d8268428fa9b9527ab63a9908 P 54fbcfe96d6d47bb930c301ac4fb0790 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "54fbcfe96d6d47bb930c301ac4fb0790" member_type: VOTER last_known_addr { host: "127.24.253.193" port: 34033 } }
I20260812 06:18:09.041426 25790 raft_consensus.cc:385] T eb19157d8268428fa9b9527ab63a9908 P 54fbcfe96d6d47bb930c301ac4fb0790 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:09.041476 25790 raft_consensus.cc:740] T eb19157d8268428fa9b9527ab63a9908 P 54fbcfe96d6d47bb930c301ac4fb0790 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 54fbcfe96d6d47bb930c301ac4fb0790, State: Initialized, Role: FOLLOWER
I20260812 06:18:09.041620 25790 consensus_queue.cc:260] T eb19157d8268428fa9b9527ab63a9908 P 54fbcfe96d6d47bb930c301ac4fb0790 [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: "54fbcfe96d6d47bb930c301ac4fb0790" member_type: VOTER last_known_addr { host: "127.24.253.193" port: 34033 } }
I20260812 06:18:09.041734 25790 raft_consensus.cc:399] T eb19157d8268428fa9b9527ab63a9908 P 54fbcfe96d6d47bb930c301ac4fb0790 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:09.041785 25790 raft_consensus.cc:493] T eb19157d8268428fa9b9527ab63a9908 P 54fbcfe96d6d47bb930c301ac4fb0790 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:09.041837 25790 raft_consensus.cc:3060] T eb19157d8268428fa9b9527ab63a9908 P 54fbcfe96d6d47bb930c301ac4fb0790 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:09.042690 25790 raft_consensus.cc:515] T eb19157d8268428fa9b9527ab63a9908 P 54fbcfe96d6d47bb930c301ac4fb0790 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "54fbcfe96d6d47bb930c301ac4fb0790" member_type: VOTER last_known_addr { host: "127.24.253.193" port: 34033 } }
I20260812 06:18:09.042889 25790 leader_election.cc:304] T eb19157d8268428fa9b9527ab63a9908 P 54fbcfe96d6d47bb930c301ac4fb0790 [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: 54fbcfe96d6d47bb930c301ac4fb0790; no voters: 
I20260812 06:18:09.043165 25790 leader_election.cc:290] T eb19157d8268428fa9b9527ab63a9908 P 54fbcfe96d6d47bb930c301ac4fb0790 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:09.043272 25792 raft_consensus.cc:2804] T eb19157d8268428fa9b9527ab63a9908 P 54fbcfe96d6d47bb930c301ac4fb0790 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:09.043524 25792 raft_consensus.cc:697] T eb19157d8268428fa9b9527ab63a9908 P 54fbcfe96d6d47bb930c301ac4fb0790 [term 1 LEADER]: Becoming Leader. State: Replica: 54fbcfe96d6d47bb930c301ac4fb0790, State: Running, Role: LEADER
I20260812 06:18:09.043591 25790 ts_tablet_manager.cc:1434] T eb19157d8268428fa9b9527ab63a9908 P 54fbcfe96d6d47bb930c301ac4fb0790: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:18:09.043787 25775 heartbeater.cc:499] Master 127.24.253.254:38683 was elected leader, sending a full tablet report...
I20260812 06:18:09.043745 25792 consensus_queue.cc:237] T eb19157d8268428fa9b9527ab63a9908 P 54fbcfe96d6d47bb930c301ac4fb0790 [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: "54fbcfe96d6d47bb930c301ac4fb0790" member_type: VOTER last_known_addr { host: "127.24.253.193" port: 34033 } }
I20260812 06:18:09.046729 25626 catalog_manager.cc:5719] T eb19157d8268428fa9b9527ab63a9908 P 54fbcfe96d6d47bb930c301ac4fb0790 reported cstate change: term changed from 0 to 1, leader changed from <none> to 54fbcfe96d6d47bb930c301ac4fb0790 (127.24.253.193). New cstate: current_term: 1 leader_uuid: "54fbcfe96d6d47bb930c301ac4fb0790" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "54fbcfe96d6d47bb930c301ac4fb0790" member_type: VOTER last_known_addr { host: "127.24.253.193" port: 34033 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:09.112263 25591 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.056s	user 0.013s	sys 0.012s
I20260812 06:18:09.242539 25777 maintenance_manager.cc:419] P 54fbcfe96d6d47bb930c301ac4fb0790: Scheduling FlushMRSOp(eb19157d8268428fa9b9527ab63a9908): perf score=18.062753
I20260812 06:18:09.403622 25707 maintenance_manager.cc:643] P 54fbcfe96d6d47bb930c301ac4fb0790: FlushMRSOp(eb19157d8268428fa9b9527ab63a9908) complete. Timing: real 0.161s	user 0.112s	sys 0.043s Metrics: {"bytes_written":8615325,"cfile_init":1,"compiler_manager_pool.queue_time_us":275,"delete_count":0,"dirs.queue_time_us":58,"dirs.run_cpu_time_us":233,"dirs.run_wall_time_us":1027,"drs_written":1,"lbm_read_time_us":82,"lbm_reads_lt_1ms":4,"lbm_write_time_us":39963,"lbm_writes_lt_1ms":667,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"thread_start_us":169,"threads_started":1,"update_count":1050}
I20260812 06:18:09.404738 25777 maintenance_manager.cc:419] P 54fbcfe96d6d47bb930c301ac4fb0790: Scheduling LogGCOp(eb19157d8268428fa9b9527ab63a9908): free 20743880 bytes of WAL
I20260812 06:18:09.405067 25707 log_reader.cc:385] T eb19157d8268428fa9b9527ab63a9908: removed 2 log segments from log reader
I20260812 06:18:09.405153 25707 log.cc:1079] T eb19157d8268428fa9b9527ab63a9908 P 54fbcfe96d6d47bb930c301ac4fb0790: Deleting log segment in path: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515488796982-25591-0/minicluster-data/ts-0-root/wals/eb19157d8268428fa9b9527ab63a9908/wal-000000001 (ops 1-6)
I20260812 06:18:09.405228 25707 log.cc:1079] T eb19157d8268428fa9b9527ab63a9908 P 54fbcfe96d6d47bb930c301ac4fb0790: Deleting log segment in path: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515488796982-25591-0/minicluster-data/ts-0-root/wals/eb19157d8268428fa9b9527ab63a9908/wal-000000002 (ops 7-11)
I20260812 06:18:09.409368 25707 maintenance_manager.cc:643] P 54fbcfe96d6d47bb930c301ac4fb0790: LogGCOp(eb19157d8268428fa9b9527ab63a9908) complete. Timing: real 0.004s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:18:09.409785 25777 maintenance_manager.cc:419] P 54fbcfe96d6d47bb930c301ac4fb0790: Scheduling UndoDeltaBlockGCOp(eb19157d8268428fa9b9527ab63a9908): 16411392 bytes on disk
I20260812 06:18:09.410437 25707 maintenance_manager.cc:643] P 54fbcfe96d6d47bb930c301ac4fb0790: UndoDeltaBlockGCOp(eb19157d8268428fa9b9527ab63a9908) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":60,"lbm_reads_lt_1ms":4}
I20260812 06:18:09.411018 25777 maintenance_manager.cc:419] P 54fbcfe96d6d47bb930c301ac4fb0790: Scheduling FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908): perf score=2.188937
I20260812 06:18:09.428423 25707 maintenance_manager.cc:643] P 54fbcfe96d6d47bb930c301ac4fb0790: FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908) complete. Timing: real 0.017s	user 0.009s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6227,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:09.428922 25777 maintenance_manager.cc:419] P 54fbcfe96d6d47bb930c301ac4fb0790: Scheduling MajorDeltaCompactionOp(eb19157d8268428fa9b9527ab63a9908): perf score=1.000000
I20260812 06:18:09.548442 25707 maintenance_manager.cc:643] P 54fbcfe96d6d47bb930c301ac4fb0790: MajorDeltaCompactionOp(eb19157d8268428fa9b9527ab63a9908) complete. Timing: real 0.119s	user 0.080s	sys 0.036s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16569858,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":443,"lbm_read_time_us":7291,"lbm_reads_lt_1ms":360,"lbm_write_time_us":21181,"lbm_writes_lt_1ms":343,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":4224,"thread_start_us":306,"threads_started":5,"update_count":1500}
I20260812 06:18:09.549062 25777 maintenance_manager.cc:419] P 54fbcfe96d6d47bb930c301ac4fb0790: Scheduling FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908): perf score=10.126437
I20260812 06:18:09.592419 25707 maintenance_manager.cc:643] P 54fbcfe96d6d47bb930c301ac4fb0790: FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908) complete. Timing: real 0.043s	user 0.031s	sys 0.004s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15369,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:09.592900 25777 maintenance_manager.cc:419] P 54fbcfe96d6d47bb930c301ac4fb0790: Scheduling FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908): perf score=2.188937
I20260812 06:18:09.603773 25707 maintenance_manager.cc:643] P 54fbcfe96d6d47bb930c301ac4fb0790: FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3945,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:09.604581 25777 maintenance_manager.cc:419] P 54fbcfe96d6d47bb930c301ac4fb0790: Scheduling MajorDeltaCompactionOp(eb19157d8268428fa9b9527ab63a9908): perf score=1.000000
I20260812 06:18:09.734756 25707 maintenance_manager.cc:643] P 54fbcfe96d6d47bb930c301ac4fb0790: MajorDeltaCompactionOp(eb19157d8268428fa9b9527ab63a9908) complete. Timing: real 0.130s	user 0.108s	sys 0.021s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":161,"lbm_read_time_us":7475,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26275,"lbm_writes_lt_1ms":443,"mutex_wait_us":43,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:18:09.735309 25777 maintenance_manager.cc:419] P 54fbcfe96d6d47bb930c301ac4fb0790: Scheduling FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908): perf score=10.126437
I20260812 06:18:09.788046 25707 maintenance_manager.cc:643] P 54fbcfe96d6d47bb930c301ac4fb0790: FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908) complete. Timing: real 0.053s	user 0.024s	sys 0.018s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14175,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:09.788579 25777 maintenance_manager.cc:419] P 54fbcfe96d6d47bb930c301ac4fb0790: Scheduling FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908): perf score=2.188937
I20260812 06:18:09.799626 25707 maintenance_manager.cc:643] P 54fbcfe96d6d47bb930c301ac4fb0790: FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4279,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:09.800216 25777 maintenance_manager.cc:419] P 54fbcfe96d6d47bb930c301ac4fb0790: Scheduling MajorDeltaCompactionOp(eb19157d8268428fa9b9527ab63a9908): perf score=1.000000
I20260812 06:18:09.957442 25707 maintenance_manager.cc:643] P 54fbcfe96d6d47bb930c301ac4fb0790: MajorDeltaCompactionOp(eb19157d8268428fa9b9527ab63a9908) complete. Timing: real 0.157s	user 0.097s	sys 0.050s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":913,"lbm_read_time_us":10411,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24828,"lbm_writes_lt_1ms":443,"mutex_wait_us":251,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:09.958148 25777 maintenance_manager.cc:419] P 54fbcfe96d6d47bb930c301ac4fb0790: Scheduling FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908): perf score=10.126437
I20260812 06:18:09.997818 25707 maintenance_manager.cc:643] P 54fbcfe96d6d47bb930c301ac4fb0790: FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908) complete. Timing: real 0.039s	user 0.020s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14865,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:09.998440 25777 maintenance_manager.cc:419] P 54fbcfe96d6d47bb930c301ac4fb0790: Scheduling MajorDeltaCompactionOp(eb19157d8268428fa9b9527ab63a9908): perf score=1.000000
I20260812 06:18:10.108892 25707 maintenance_manager.cc:643] P 54fbcfe96d6d47bb930c301ac4fb0790: MajorDeltaCompactionOp(eb19157d8268428fa9b9527ab63a9908) complete. Timing: real 0.110s	user 0.078s	sys 0.028s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16569746,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":1092,"lbm_read_time_us":7303,"lbm_reads_lt_1ms":363,"lbm_write_time_us":20719,"lbm_writes_lt_1ms":343,"mutex_wait_us":284,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":1500}
I20260812 06:18:10.109524 25777 maintenance_manager.cc:419] P 54fbcfe96d6d47bb930c301ac4fb0790: Scheduling FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908): perf score=10.126437
I20260812 06:18:10.145280 25707 maintenance_manager.cc:643] P 54fbcfe96d6d47bb930c301ac4fb0790: FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908) complete. Timing: real 0.036s	user 0.030s	sys 0.004s Metrics: {"bytes_written":12307667,"delete_count":0,"lbm_write_time_us":14673,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:10.145833 25777 maintenance_manager.cc:419] P 54fbcfe96d6d47bb930c301ac4fb0790: Scheduling MajorDeltaCompactionOp(eb19157d8268428fa9b9527ab63a9908): perf score=1.000000
I20260812 06:18:10.258606 25707 maintenance_manager.cc:643] P 54fbcfe96d6d47bb930c301ac4fb0790: MajorDeltaCompactionOp(eb19157d8268428fa9b9527ab63a9908) complete. Timing: real 0.113s	user 0.090s	sys 0.021s Metrics: {"cfile_cache_miss":331,"cfile_cache_miss_bytes":16569923,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":184,"lbm_read_time_us":7651,"lbm_reads_lt_1ms":363,"lbm_write_time_us":22255,"lbm_writes_lt_1ms":343,"mutex_wait_us":39,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":1500}
I20260812 06:18:10.259258 25777 maintenance_manager.cc:419] P 54fbcfe96d6d47bb930c301ac4fb0790: Scheduling FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908): perf score=10.126437
I20260812 06:18:10.307735 25707 maintenance_manager.cc:643] P 54fbcfe96d6d47bb930c301ac4fb0790: FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908) complete. Timing: real 0.048s	user 0.022s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16678,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:10.308343 25777 maintenance_manager.cc:419] P 54fbcfe96d6d47bb930c301ac4fb0790: Scheduling FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908): perf score=2.188937
I20260812 06:18:10.319078 25707 maintenance_manager.cc:643] P 54fbcfe96d6d47bb930c301ac4fb0790: FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3997,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:10.319890 25777 maintenance_manager.cc:419] P 54fbcfe96d6d47bb930c301ac4fb0790: Scheduling MajorDeltaCompactionOp(eb19157d8268428fa9b9527ab63a9908): perf score=1.000000
I20260812 06:18:10.436563 25707 maintenance_manager.cc:643] P 54fbcfe96d6d47bb930c301ac4fb0790: MajorDeltaCompactionOp(eb19157d8268428fa9b9527ab63a9908) complete. Timing: real 0.116s	user 0.100s	sys 0.017s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":637,"lbm_read_time_us":8148,"lbm_reads_lt_1ms":472,"lbm_write_time_us":21889,"lbm_writes_lt_1ms":443,"mutex_wait_us":34,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:10.437153 25777 maintenance_manager.cc:419] P 54fbcfe96d6d47bb930c301ac4fb0790: Scheduling FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908): perf score=10.126437
I20260812 06:18:10.480351 25707 maintenance_manager.cc:643] P 54fbcfe96d6d47bb930c301ac4fb0790: FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908) complete. Timing: real 0.043s	user 0.025s	sys 0.012s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":16186,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:10.480861 25777 maintenance_manager.cc:419] P 54fbcfe96d6d47bb930c301ac4fb0790: Scheduling FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908): perf score=2.188937
I20260812 06:18:10.491349 25707 maintenance_manager.cc:643] P 54fbcfe96d6d47bb930c301ac4fb0790: FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3935,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:10.492030 25777 maintenance_manager.cc:419] P 54fbcfe96d6d47bb930c301ac4fb0790: Scheduling MajorDeltaCompactionOp(eb19157d8268428fa9b9527ab63a9908): perf score=1.000000
I20260812 06:18:10.621420 25707 maintenance_manager.cc:643] P 54fbcfe96d6d47bb930c301ac4fb0790: MajorDeltaCompactionOp(eb19157d8268428fa9b9527ab63a9908) complete. Timing: real 0.129s	user 0.114s	sys 0.015s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":272,"lbm_read_time_us":8809,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23720,"lbm_writes_lt_1ms":443,"mutex_wait_us":34,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":5248,"update_count":2000}
I20260812 06:18:10.622012 25777 maintenance_manager.cc:419] P 54fbcfe96d6d47bb930c301ac4fb0790: Scheduling FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908): perf score=10.126437
I20260812 06:18:10.670042 25707 maintenance_manager.cc:643] P 54fbcfe96d6d47bb930c301ac4fb0790: FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908) complete. Timing: real 0.048s	user 0.024s	sys 0.010s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":15564,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:10.670583 25777 maintenance_manager.cc:419] P 54fbcfe96d6d47bb930c301ac4fb0790: Scheduling FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908): perf score=2.188937
I20260812 06:18:10.686153 25707 maintenance_manager.cc:643] P 54fbcfe96d6d47bb930c301ac4fb0790: FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908) complete. Timing: real 0.015s	user 0.008s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5790,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:10.686882 25777 maintenance_manager.cc:419] P 54fbcfe96d6d47bb930c301ac4fb0790: Scheduling FlushMRSOp(eb19157d8268428fa9b9527ab63a9908): perf score=1.000000
I20260812 06:18:10.722540 25707 maintenance_manager.cc:643] P 54fbcfe96d6d47bb930c301ac4fb0790: FlushMRSOp(eb19157d8268428fa9b9527ab63a9908) complete. Timing: real 0.035s	user 0.034s	sys 0.000s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":120,"dirs.run_cpu_time_us":255,"dirs.run_wall_time_us":1587,"drs_written":1,"lbm_read_time_us":47,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1564,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:18:10.723367 25777 maintenance_manager.cc:419] P 54fbcfe96d6d47bb930c301ac4fb0790: Scheduling LogGCOp(eb19157d8268428fa9b9527ab63a9908): free 120553372 bytes of WAL
I20260812 06:18:10.723624 25707 log_reader.cc:385] T eb19157d8268428fa9b9527ab63a9908: removed 12 log segments from log reader
I20260812 06:18:10.723670 25707 log.cc:1079] T eb19157d8268428fa9b9527ab63a9908 P 54fbcfe96d6d47bb930c301ac4fb0790: Deleting log segment in path: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515488796982-25591-0/minicluster-data/ts-0-root/wals/eb19157d8268428fa9b9527ab63a9908/wal-000000003 (ops 12-16)
I20260812 06:18:10.723699 25707 log.cc:1079] T eb19157d8268428fa9b9527ab63a9908 P 54fbcfe96d6d47bb930c301ac4fb0790: Deleting log segment in path: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515488796982-25591-0/minicluster-data/ts-0-root/wals/eb19157d8268428fa9b9527ab63a9908/wal-000000004 (ops 17-20)
I20260812 06:18:10.723762 25707 log.cc:1079] T eb19157d8268428fa9b9527ab63a9908 P 54fbcfe96d6d47bb930c301ac4fb0790: Deleting log segment in path: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515488796982-25591-0/minicluster-data/ts-0-root/wals/eb19157d8268428fa9b9527ab63a9908/wal-000000005 (ops 21-25)
I20260812 06:18:10.723809 25707 log.cc:1079] T eb19157d8268428fa9b9527ab63a9908 P 54fbcfe96d6d47bb930c301ac4fb0790: Deleting log segment in path: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515488796982-25591-0/minicluster-data/ts-0-root/wals/eb19157d8268428fa9b9527ab63a9908/wal-000000006 (ops 26-30)
I20260812 06:18:10.723882 25707 log.cc:1079] T eb19157d8268428fa9b9527ab63a9908 P 54fbcfe96d6d47bb930c301ac4fb0790: Deleting log segment in path: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515488796982-25591-0/minicluster-data/ts-0-root/wals/eb19157d8268428fa9b9527ab63a9908/wal-000000007 (ops 31-35)
I20260812 06:18:10.723923 25707 log.cc:1079] T eb19157d8268428fa9b9527ab63a9908 P 54fbcfe96d6d47bb930c301ac4fb0790: Deleting log segment in path: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515488796982-25591-0/minicluster-data/ts-0-root/wals/eb19157d8268428fa9b9527ab63a9908/wal-000000008 (ops 36-40)
I20260812 06:18:10.723963 25707 log.cc:1079] T eb19157d8268428fa9b9527ab63a9908 P 54fbcfe96d6d47bb930c301ac4fb0790: Deleting log segment in path: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515488796982-25591-0/minicluster-data/ts-0-root/wals/eb19157d8268428fa9b9527ab63a9908/wal-000000009 (ops 41-45)
I20260812 06:18:10.724000 25707 log.cc:1079] T eb19157d8268428fa9b9527ab63a9908 P 54fbcfe96d6d47bb930c301ac4fb0790: Deleting log segment in path: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515488796982-25591-0/minicluster-data/ts-0-root/wals/eb19157d8268428fa9b9527ab63a9908/wal-000000010 (ops 46-50)
I20260812 06:18:10.724040 25707 log.cc:1079] T eb19157d8268428fa9b9527ab63a9908 P 54fbcfe96d6d47bb930c301ac4fb0790: Deleting log segment in path: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515488796982-25591-0/minicluster-data/ts-0-root/wals/eb19157d8268428fa9b9527ab63a9908/wal-000000011 (ops 51-55)
I20260812 06:18:10.724078 25707 log.cc:1079] T eb19157d8268428fa9b9527ab63a9908 P 54fbcfe96d6d47bb930c301ac4fb0790: Deleting log segment in path: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515488796982-25591-0/minicluster-data/ts-0-root/wals/eb19157d8268428fa9b9527ab63a9908/wal-000000012 (ops 56-60)
I20260812 06:18:10.724118 25707 log.cc:1079] T eb19157d8268428fa9b9527ab63a9908 P 54fbcfe96d6d47bb930c301ac4fb0790: Deleting log segment in path: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515488796982-25591-0/minicluster-data/ts-0-root/wals/eb19157d8268428fa9b9527ab63a9908/wal-000000013 (ops 61-64)
I20260812 06:18:10.724159 25707 log.cc:1079] T eb19157d8268428fa9b9527ab63a9908 P 54fbcfe96d6d47bb930c301ac4fb0790: Deleting log segment in path: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515488796982-25591-0/minicluster-data/ts-0-root/wals/eb19157d8268428fa9b9527ab63a9908/wal-000000014 (ops 65-69)
I20260812 06:18:10.749825 25707 maintenance_manager.cc:643] P 54fbcfe96d6d47bb930c301ac4fb0790: LogGCOp(eb19157d8268428fa9b9527ab63a9908) complete. Timing: real 0.026s	user 0.002s	sys 0.023s Metrics: {}
I20260812 06:18:10.750519 25777 maintenance_manager.cc:419] P 54fbcfe96d6d47bb930c301ac4fb0790: Scheduling UndoDeltaBlockGCOp(eb19157d8268428fa9b9527ab63a9908): 463 bytes on disk
I20260812 06:18:10.750962 25707 maintenance_manager.cc:643] P 54fbcfe96d6d47bb930c301ac4fb0790: UndoDeltaBlockGCOp(eb19157d8268428fa9b9527ab63a9908) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":51,"lbm_reads_lt_1ms":4}
I20260812 06:18:10.751488 25777 maintenance_manager.cc:419] P 54fbcfe96d6d47bb930c301ac4fb0790: Scheduling FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908): perf score=4.173312
I20260812 06:18:10.766101 25707 maintenance_manager.cc:643] P 54fbcfe96d6d47bb930c301ac4fb0790: FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908) complete. Timing: real 0.014s	user 0.009s	sys 0.003s Metrics: {"bytes_written":5579537,"delete_count":0,"lbm_write_time_us":5874,"lbm_writes_lt_1ms":139,"reinsert_count":0,"update_count":680}
I20260812 06:18:10.766577 25777 maintenance_manager.cc:419] P 54fbcfe96d6d47bb930c301ac4fb0790: Scheduling FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908): perf score=1.196750
I20260812 06:18:10.775041 25707 maintenance_manager.cc:643] P 54fbcfe96d6d47bb930c301ac4fb0790: FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908) complete. Timing: real 0.008s	user 0.003s	sys 0.003s Metrics: {"bytes_written":2625754,"delete_count":0,"lbm_write_time_us":2834,"lbm_writes_lt_1ms":67,"reinsert_count":0,"update_count":320}
I20260812 06:18:10.775652 25777 maintenance_manager.cc:419] P 54fbcfe96d6d47bb930c301ac4fb0790: Scheduling MajorDeltaCompactionOp(eb19157d8268428fa9b9527ab63a9908): perf score=1.000000
I20260812 06:18:10.962786 25707 maintenance_manager.cc:643] P 54fbcfe96d6d47bb930c301ac4fb0790: MajorDeltaCompactionOp(eb19157d8268428fa9b9527ab63a9908) complete. Timing: real 0.187s	user 0.142s	sys 0.036s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877305,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":347,"lbm_read_time_us":10748,"lbm_reads_lt_1ms":674,"lbm_write_time_us":39769,"lbm_writes_lt_1ms":643,"mutex_wait_us":73,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":10624,"thread_start_us":76,"threads_started":1,"update_count":3000}
I20260812 06:18:10.963526 25777 maintenance_manager.cc:419] P 54fbcfe96d6d47bb930c301ac4fb0790: Scheduling FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908): perf score=14.095187
I20260812 06:18:11.015178 25707 maintenance_manager.cc:643] P 54fbcfe96d6d47bb930c301ac4fb0790: FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908) complete. Timing: real 0.051s	user 0.028s	sys 0.011s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18648,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:11.015779 25777 maintenance_manager.cc:419] P 54fbcfe96d6d47bb930c301ac4fb0790: Scheduling FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908): perf score=2.188937
I20260812 06:18:11.030016 25707 maintenance_manager.cc:643] P 54fbcfe96d6d47bb930c301ac4fb0790: FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908) complete. Timing: real 0.014s	user 0.011s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4733,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:11.030580 25777 maintenance_manager.cc:419] P 54fbcfe96d6d47bb930c301ac4fb0790: Scheduling MajorDeltaCompactionOp(eb19157d8268428fa9b9527ab63a9908): perf score=1.000000
I20260812 06:18:11.190502 25707 maintenance_manager.cc:643] P 54fbcfe96d6d47bb930c301ac4fb0790: MajorDeltaCompactionOp(eb19157d8268428fa9b9527ab63a9908) complete. Timing: real 0.160s	user 0.118s	sys 0.033s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":346,"lbm_read_time_us":10275,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31750,"lbm_writes_lt_1ms":543,"mutex_wait_us":50,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1536,"update_count":2500}
I20260812 06:18:11.191167 25777 maintenance_manager.cc:419] P 54fbcfe96d6d47bb930c301ac4fb0790: Scheduling FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908): perf score=11.118625
I20260812 06:18:11.225955 25707 maintenance_manager.cc:643] P 54fbcfe96d6d47bb930c301ac4fb0790: FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908) complete. Timing: real 0.034s	user 0.013s	sys 0.020s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":14666,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:11.227043 25777 maintenance_manager.cc:419] P 54fbcfe96d6d47bb930c301ac4fb0790: Scheduling FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908): perf score=2.188937
I20260812 06:18:11.241179 25707 maintenance_manager.cc:643] P 54fbcfe96d6d47bb930c301ac4fb0790: FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908) complete. Timing: real 0.014s	user 0.009s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5233,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:11.241696 25777 maintenance_manager.cc:419] P 54fbcfe96d6d47bb930c301ac4fb0790: Scheduling MajorDeltaCompactionOp(eb19157d8268428fa9b9527ab63a9908): perf score=1.000000
I20260812 06:18:11.387121 25707 maintenance_manager.cc:643] P 54fbcfe96d6d47bb930c301ac4fb0790: MajorDeltaCompactionOp(eb19157d8268428fa9b9527ab63a9908) complete. Timing: real 0.145s	user 0.097s	sys 0.048s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672269,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":141,"lbm_read_time_us":11097,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24942,"lbm_writes_lt_1ms":443,"mutex_wait_us":49,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11008,"update_count":2000}
I20260812 06:18:11.389760 25777 maintenance_manager.cc:419] P 54fbcfe96d6d47bb930c301ac4fb0790: Scheduling FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908): perf score=10.126437
I20260812 06:18:11.440543 25707 maintenance_manager.cc:643] P 54fbcfe96d6d47bb930c301ac4fb0790: FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908) complete. Timing: real 0.050s	user 0.024s	sys 0.024s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17896,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:11.441181 25777 maintenance_manager.cc:419] P 54fbcfe96d6d47bb930c301ac4fb0790: Scheduling FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908): perf score=2.188937
I20260812 06:18:11.452232 25707 maintenance_manager.cc:643] P 54fbcfe96d6d47bb930c301ac4fb0790: FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4286,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:11.452719 25777 maintenance_manager.cc:419] P 54fbcfe96d6d47bb930c301ac4fb0790: Scheduling MajorDeltaCompactionOp(eb19157d8268428fa9b9527ab63a9908): perf score=1.000000
I20260812 06:18:11.595391 25707 maintenance_manager.cc:643] P 54fbcfe96d6d47bb930c301ac4fb0790: MajorDeltaCompactionOp(eb19157d8268428fa9b9527ab63a9908) complete. Timing: real 0.142s	user 0.110s	sys 0.027s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":2167,"lbm_read_time_us":12514,"lbm_reads_1-10_ms":1,"lbm_reads_lt_1ms":471,"lbm_write_time_us":21576,"lbm_writes_lt_1ms":443,"mutex_wait_us":629,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:11.596051 25777 maintenance_manager.cc:419] P 54fbcfe96d6d47bb930c301ac4fb0790: Scheduling FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908): perf score=10.126437
I20260812 06:18:11.646057 25707 maintenance_manager.cc:643] P 54fbcfe96d6d47bb930c301ac4fb0790: FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908) complete. Timing: real 0.050s	user 0.018s	sys 0.017s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16640,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:11.646548 25777 maintenance_manager.cc:419] P 54fbcfe96d6d47bb930c301ac4fb0790: Scheduling FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908): perf score=2.188937
I20260812 06:18:11.658452 25707 maintenance_manager.cc:643] P 54fbcfe96d6d47bb930c301ac4fb0790: FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4227,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:11.659164 25777 maintenance_manager.cc:419] P 54fbcfe96d6d47bb930c301ac4fb0790: Scheduling MajorDeltaCompactionOp(eb19157d8268428fa9b9527ab63a9908): perf score=1.000000
I20260812 06:18:11.795887 25707 maintenance_manager.cc:643] P 54fbcfe96d6d47bb930c301ac4fb0790: MajorDeltaCompactionOp(eb19157d8268428fa9b9527ab63a9908) complete. Timing: real 0.136s	user 0.101s	sys 0.035s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":749,"lbm_read_time_us":10307,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25879,"lbm_writes_lt_1ms":443,"mutex_wait_us":272,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11520,"update_count":2000}
I20260812 06:18:11.796620 25777 maintenance_manager.cc:419] P 54fbcfe96d6d47bb930c301ac4fb0790: Scheduling FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908): perf score=10.126437
I20260812 06:18:11.836030 25707 maintenance_manager.cc:643] P 54fbcfe96d6d47bb930c301ac4fb0790: FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908) complete. Timing: real 0.039s	user 0.025s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14198,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:11.836513 25777 maintenance_manager.cc:419] P 54fbcfe96d6d47bb930c301ac4fb0790: Scheduling FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908): perf score=2.188937
I20260812 06:18:11.847503 25707 maintenance_manager.cc:643] P 54fbcfe96d6d47bb930c301ac4fb0790: FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4211,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:11.848409 25777 maintenance_manager.cc:419] P 54fbcfe96d6d47bb930c301ac4fb0790: Scheduling MajorDeltaCompactionOp(eb19157d8268428fa9b9527ab63a9908): perf score=1.000000
I20260812 06:18:11.985299 25707 maintenance_manager.cc:643] P 54fbcfe96d6d47bb930c301ac4fb0790: MajorDeltaCompactionOp(eb19157d8268428fa9b9527ab63a9908) complete. Timing: real 0.137s	user 0.114s	sys 0.022s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1830,"lbm_read_time_us":8785,"lbm_reads_lt_1ms":472,"lbm_write_time_us":27256,"lbm_writes_lt_1ms":443,"mutex_wait_us":366,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1536,"update_count":2000}
I20260812 06:18:11.986093 25777 maintenance_manager.cc:419] P 54fbcfe96d6d47bb930c301ac4fb0790: Scheduling FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908): perf score=10.126437
I20260812 06:18:12.040758 25707 maintenance_manager.cc:643] P 54fbcfe96d6d47bb930c301ac4fb0790: FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908) complete. Timing: real 0.054s	user 0.029s	sys 0.016s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17047,"lbm_writes_lt_1ms":303,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":1500}
I20260812 06:18:12.041464 25777 maintenance_manager.cc:419] P 54fbcfe96d6d47bb930c301ac4fb0790: Scheduling FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908): perf score=2.188937
I20260812 06:18:12.052547 25707 maintenance_manager.cc:643] P 54fbcfe96d6d47bb930c301ac4fb0790: FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908) complete. Timing: real 0.011s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4191,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:12.053089 25777 maintenance_manager.cc:419] P 54fbcfe96d6d47bb930c301ac4fb0790: Scheduling MajorDeltaCompactionOp(eb19157d8268428fa9b9527ab63a9908): perf score=1.000000
I20260812 06:18:12.206288 25707 maintenance_manager.cc:643] P 54fbcfe96d6d47bb930c301ac4fb0790: MajorDeltaCompactionOp(eb19157d8268428fa9b9527ab63a9908) complete. Timing: real 0.153s	user 0.103s	sys 0.048s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":639,"lbm_read_time_us":11764,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23921,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6528,"update_count":2000}
I20260812 06:18:12.206923 25777 maintenance_manager.cc:419] P 54fbcfe96d6d47bb930c301ac4fb0790: Scheduling FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908): perf score=10.126437
I20260812 06:18:12.260702 25707 maintenance_manager.cc:643] P 54fbcfe96d6d47bb930c301ac4fb0790: FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908) complete. Timing: real 0.054s	user 0.019s	sys 0.028s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":21186,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:18:12.261251 25777 maintenance_manager.cc:419] P 54fbcfe96d6d47bb930c301ac4fb0790: Scheduling FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908): perf score=2.188937
I20260812 06:18:12.272217 25707 maintenance_manager.cc:643] P 54fbcfe96d6d47bb930c301ac4fb0790: FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4013,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:12.272881 25777 maintenance_manager.cc:419] P 54fbcfe96d6d47bb930c301ac4fb0790: Scheduling FlushMRSOp(eb19157d8268428fa9b9527ab63a9908): perf score=1.000000
I20260812 06:18:12.305281 25707 maintenance_manager.cc:643] P 54fbcfe96d6d47bb930c301ac4fb0790: FlushMRSOp(eb19157d8268428fa9b9527ab63a9908) complete. Timing: real 0.032s	user 0.030s	sys 0.000s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":67,"dirs.run_cpu_time_us":215,"dirs.run_wall_time_us":1507,"drs_written":1,"lbm_read_time_us":113,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1526,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:18:12.305979 25777 maintenance_manager.cc:419] P 54fbcfe96d6d47bb930c301ac4fb0790: Scheduling LogGCOp(eb19157d8268428fa9b9527ab63a9908): free 120553336 bytes of WAL
I20260812 06:18:12.306209 25707 log_reader.cc:385] T eb19157d8268428fa9b9527ab63a9908: removed 12 log segments from log reader
I20260812 06:18:12.306253 25707 log.cc:1079] T eb19157d8268428fa9b9527ab63a9908 P 54fbcfe96d6d47bb930c301ac4fb0790: Deleting log segment in path: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515488796982-25591-0/minicluster-data/ts-0-root/wals/eb19157d8268428fa9b9527ab63a9908/wal-000000015 (ops 70-74)
I20260812 06:18:12.306281 25707 log.cc:1079] T eb19157d8268428fa9b9527ab63a9908 P 54fbcfe96d6d47bb930c301ac4fb0790: Deleting log segment in path: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515488796982-25591-0/minicluster-data/ts-0-root/wals/eb19157d8268428fa9b9527ab63a9908/wal-000000016 (ops 75-79)
I20260812 06:18:12.306344 25707 log.cc:1079] T eb19157d8268428fa9b9527ab63a9908 P 54fbcfe96d6d47bb930c301ac4fb0790: Deleting log segment in path: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515488796982-25591-0/minicluster-data/ts-0-root/wals/eb19157d8268428fa9b9527ab63a9908/wal-000000017 (ops 80-84)
I20260812 06:18:12.306375 25707 log.cc:1079] T eb19157d8268428fa9b9527ab63a9908 P 54fbcfe96d6d47bb930c301ac4fb0790: Deleting log segment in path: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515488796982-25591-0/minicluster-data/ts-0-root/wals/eb19157d8268428fa9b9527ab63a9908/wal-000000018 (ops 85-88)
I20260812 06:18:12.306411 25707 log.cc:1079] T eb19157d8268428fa9b9527ab63a9908 P 54fbcfe96d6d47bb930c301ac4fb0790: Deleting log segment in path: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515488796982-25591-0/minicluster-data/ts-0-root/wals/eb19157d8268428fa9b9527ab63a9908/wal-000000019 (ops 89-93)
I20260812 06:18:12.306437 25707 log.cc:1079] T eb19157d8268428fa9b9527ab63a9908 P 54fbcfe96d6d47bb930c301ac4fb0790: Deleting log segment in path: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515488796982-25591-0/minicluster-data/ts-0-root/wals/eb19157d8268428fa9b9527ab63a9908/wal-000000020 (ops 94-98)
I20260812 06:18:12.306473 25707 log.cc:1079] T eb19157d8268428fa9b9527ab63a9908 P 54fbcfe96d6d47bb930c301ac4fb0790: Deleting log segment in path: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515488796982-25591-0/minicluster-data/ts-0-root/wals/eb19157d8268428fa9b9527ab63a9908/wal-000000021 (ops 99-103)
I20260812 06:18:12.306510 25707 log.cc:1079] T eb19157d8268428fa9b9527ab63a9908 P 54fbcfe96d6d47bb930c301ac4fb0790: Deleting log segment in path: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515488796982-25591-0/minicluster-data/ts-0-root/wals/eb19157d8268428fa9b9527ab63a9908/wal-000000022 (ops 104-108)
I20260812 06:18:12.306548 25707 log.cc:1079] T eb19157d8268428fa9b9527ab63a9908 P 54fbcfe96d6d47bb930c301ac4fb0790: Deleting log segment in path: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515488796982-25591-0/minicluster-data/ts-0-root/wals/eb19157d8268428fa9b9527ab63a9908/wal-000000023 (ops 109-112)
I20260812 06:18:12.306586 25707 log.cc:1079] T eb19157d8268428fa9b9527ab63a9908 P 54fbcfe96d6d47bb930c301ac4fb0790: Deleting log segment in path: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515488796982-25591-0/minicluster-data/ts-0-root/wals/eb19157d8268428fa9b9527ab63a9908/wal-000000024 (ops 113-117)
I20260812 06:18:12.306627 25707 log.cc:1079] T eb19157d8268428fa9b9527ab63a9908 P 54fbcfe96d6d47bb930c301ac4fb0790: Deleting log segment in path: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515488796982-25591-0/minicluster-data/ts-0-root/wals/eb19157d8268428fa9b9527ab63a9908/wal-000000025 (ops 118-122)
I20260812 06:18:12.306663 25707 log.cc:1079] T eb19157d8268428fa9b9527ab63a9908 P 54fbcfe96d6d47bb930c301ac4fb0790: Deleting log segment in path: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515488796982-25591-0/minicluster-data/ts-0-root/wals/eb19157d8268428fa9b9527ab63a9908/wal-000000026 (ops 123-127)
I20260812 06:18:12.333412 25707 maintenance_manager.cc:643] P 54fbcfe96d6d47bb930c301ac4fb0790: LogGCOp(eb19157d8268428fa9b9527ab63a9908) complete. Timing: real 0.027s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:18:12.333834 25777 maintenance_manager.cc:419] P 54fbcfe96d6d47bb930c301ac4fb0790: Scheduling UndoDeltaBlockGCOp(eb19157d8268428fa9b9527ab63a9908): 482 bytes on disk
I20260812 06:18:12.334340 25707 maintenance_manager.cc:643] P 54fbcfe96d6d47bb930c301ac4fb0790: UndoDeltaBlockGCOp(eb19157d8268428fa9b9527ab63a9908) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":68,"lbm_reads_lt_1ms":4}
I20260812 06:18:12.334846 25777 maintenance_manager.cc:419] P 54fbcfe96d6d47bb930c301ac4fb0790: Scheduling FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908): perf score=3.181125
I20260812 06:18:12.361687 25707 maintenance_manager.cc:643] P 54fbcfe96d6d47bb930c301ac4fb0790: FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908) complete. Timing: real 0.027s	user 0.008s	sys 0.016s Metrics: {"bytes_written":4512902,"delete_count":0,"lbm_write_time_us":7285,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:12.362246 25777 maintenance_manager.cc:419] P 54fbcfe96d6d47bb930c301ac4fb0790: Scheduling LogGCOp(eb19157d8268428fa9b9527ab63a9908): free 12018000 bytes of WAL
I20260812 06:18:12.362466 25707 log_reader.cc:385] T eb19157d8268428fa9b9527ab63a9908: removed 1 log segments from log reader
I20260812 06:18:12.362521 25707 log.cc:1079] T eb19157d8268428fa9b9527ab63a9908 P 54fbcfe96d6d47bb930c301ac4fb0790: Deleting log segment in path: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515488796982-25591-0/minicluster-data/ts-0-root/wals/eb19157d8268428fa9b9527ab63a9908/wal-000000027 (ops 128-132)
I20260812 06:18:12.365491 25707 maintenance_manager.cc:643] P 54fbcfe96d6d47bb930c301ac4fb0790: LogGCOp(eb19157d8268428fa9b9527ab63a9908) complete. Timing: real 0.003s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:18:12.365851 25777 maintenance_manager.cc:419] P 54fbcfe96d6d47bb930c301ac4fb0790: Scheduling FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908): perf score=2.188937
I20260812 06:18:12.376341 25707 maintenance_manager.cc:643] P 54fbcfe96d6d47bb930c301ac4fb0790: FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908) complete. Timing: real 0.010s	user 0.009s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3834,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:12.376777 25777 maintenance_manager.cc:419] P 54fbcfe96d6d47bb930c301ac4fb0790: Scheduling MajorDeltaCompactionOp(eb19157d8268428fa9b9527ab63a9908): perf score=1.000000
I20260812 06:18:12.577019 25707 maintenance_manager.cc:643] P 54fbcfe96d6d47bb930c301ac4fb0790: MajorDeltaCompactionOp(eb19157d8268428fa9b9527ab63a9908) complete. Timing: real 0.200s	user 0.127s	sys 0.063s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877328,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":485,"lbm_read_time_us":13955,"lbm_reads_lt_1ms":674,"lbm_write_time_us":34119,"lbm_writes_lt_1ms":643,"mutex_wait_us":69,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":17664,"thread_start_us":82,"threads_started":1,"update_count":3000}
I20260812 06:18:12.577841 25777 maintenance_manager.cc:419] P 54fbcfe96d6d47bb930c301ac4fb0790: Scheduling FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908): perf score=14.095187
I20260812 06:18:12.644898 25707 maintenance_manager.cc:643] P 54fbcfe96d6d47bb930c301ac4fb0790: FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908) complete. Timing: real 0.067s	user 0.026s	sys 0.035s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":23664,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:12.645519 25777 maintenance_manager.cc:419] P 54fbcfe96d6d47bb930c301ac4fb0790: Scheduling FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908): perf score=2.188937
I20260812 06:18:12.656477 25707 maintenance_manager.cc:643] P 54fbcfe96d6d47bb930c301ac4fb0790: FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4141,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:12.657007 25777 maintenance_manager.cc:419] P 54fbcfe96d6d47bb930c301ac4fb0790: Scheduling MajorDeltaCompactionOp(eb19157d8268428fa9b9527ab63a9908): perf score=1.000000
I20260812 06:18:12.823459 25707 maintenance_manager.cc:643] P 54fbcfe96d6d47bb930c301ac4fb0790: MajorDeltaCompactionOp(eb19157d8268428fa9b9527ab63a9908) complete. Timing: real 0.166s	user 0.109s	sys 0.055s 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":203,"lbm_read_time_us":13886,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25955,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12928,"update_count":2500}
I20260812 06:18:12.824231 25777 maintenance_manager.cc:419] P 54fbcfe96d6d47bb930c301ac4fb0790: Scheduling FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908): perf score=10.126437
I20260812 06:18:12.859514 25707 maintenance_manager.cc:643] P 54fbcfe96d6d47bb930c301ac4fb0790: FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908) complete. Timing: real 0.035s	user 0.024s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14766,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:12.860477 25777 maintenance_manager.cc:419] P 54fbcfe96d6d47bb930c301ac4fb0790: Scheduling FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908): perf score=2.188937
I20260812 06:18:12.889724 25707 maintenance_manager.cc:643] P 54fbcfe96d6d47bb930c301ac4fb0790: FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908) complete. Timing: real 0.029s	user 0.008s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6886,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:12.890215 25777 maintenance_manager.cc:419] P 54fbcfe96d6d47bb930c301ac4fb0790: Scheduling FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908): perf score=2.188937
I20260812 06:18:12.910315 25707 maintenance_manager.cc:643] P 54fbcfe96d6d47bb930c301ac4fb0790: FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908) complete. Timing: real 0.020s	user 0.006s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4976,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:12.910903 25777 maintenance_manager.cc:419] P 54fbcfe96d6d47bb930c301ac4fb0790: Scheduling MajorDeltaCompactionOp(eb19157d8268428fa9b9527ab63a9908): perf score=1.000000
I20260812 06:18:13.076265 25707 maintenance_manager.cc:643] P 54fbcfe96d6d47bb930c301ac4fb0790: MajorDeltaCompactionOp(eb19157d8268428fa9b9527ab63a9908) complete. Timing: real 0.165s	user 0.113s	sys 0.052s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774808,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":246,"lbm_read_time_us":12609,"lbm_reads_lt_1ms":573,"lbm_write_time_us":27494,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:18:13.077499 25777 maintenance_manager.cc:419] P 54fbcfe96d6d47bb930c301ac4fb0790: Scheduling FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908): perf score=10.126437
I20260812 06:18:13.114948 25707 maintenance_manager.cc:643] P 54fbcfe96d6d47bb930c301ac4fb0790: FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908) complete. Timing: real 0.037s	user 0.027s	sys 0.007s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15692,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:13.115614 25777 maintenance_manager.cc:419] P 54fbcfe96d6d47bb930c301ac4fb0790: Scheduling FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908): perf score=2.188937
I20260812 06:18:13.134457 25707 maintenance_manager.cc:643] P 54fbcfe96d6d47bb930c301ac4fb0790: FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908) complete. Timing: real 0.019s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6005,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:13.134956 25777 maintenance_manager.cc:419] P 54fbcfe96d6d47bb930c301ac4fb0790: Scheduling MajorDeltaCompactionOp(eb19157d8268428fa9b9527ab63a9908): perf score=1.000000
I20260812 06:18:13.254143 25707 maintenance_manager.cc:643] P 54fbcfe96d6d47bb930c301ac4fb0790: MajorDeltaCompactionOp(eb19157d8268428fa9b9527ab63a9908) complete. Timing: real 0.119s	user 0.081s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":168,"lbm_read_time_us":7389,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23734,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:13.255164 25777 maintenance_manager.cc:419] P 54fbcfe96d6d47bb930c301ac4fb0790: Scheduling FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908): perf score=10.126437
I20260812 06:18:13.287168 25707 maintenance_manager.cc:643] P 54fbcfe96d6d47bb930c301ac4fb0790: FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908) complete. Timing: real 0.032s	user 0.026s	sys 0.003s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13636,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:13.287891 25777 maintenance_manager.cc:419] P 54fbcfe96d6d47bb930c301ac4fb0790: Scheduling FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908): perf score=2.188937
I20260812 06:18:13.303233 25707 maintenance_manager.cc:643] P 54fbcfe96d6d47bb930c301ac4fb0790: FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908) complete. Timing: real 0.015s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5701,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:13.303725 25777 maintenance_manager.cc:419] P 54fbcfe96d6d47bb930c301ac4fb0790: Scheduling MajorDeltaCompactionOp(eb19157d8268428fa9b9527ab63a9908): perf score=1.000000
I20260812 06:18:13.428534 25707 maintenance_manager.cc:643] P 54fbcfe96d6d47bb930c301ac4fb0790: MajorDeltaCompactionOp(eb19157d8268428fa9b9527ab63a9908) complete. Timing: real 0.125s	user 0.104s	sys 0.021s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":561,"lbm_read_time_us":7644,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24156,"lbm_writes_lt_1ms":443,"mutex_wait_us":50,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6784,"update_count":2000}
I20260812 06:18:13.429364 25777 maintenance_manager.cc:419] P 54fbcfe96d6d47bb930c301ac4fb0790: Scheduling FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908): perf score=10.126437
I20260812 06:18:13.475622 25707 maintenance_manager.cc:643] P 54fbcfe96d6d47bb930c301ac4fb0790: FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908) complete. Timing: real 0.046s	user 0.029s	sys 0.008s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":16604,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:13.476300 25777 maintenance_manager.cc:419] P 54fbcfe96d6d47bb930c301ac4fb0790: Scheduling FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908): perf score=2.188937
I20260812 06:18:13.487353 25707 maintenance_manager.cc:643] P 54fbcfe96d6d47bb930c301ac4fb0790: FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4099,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:13.488062 25777 maintenance_manager.cc:419] P 54fbcfe96d6d47bb930c301ac4fb0790: Scheduling MajorDeltaCompactionOp(eb19157d8268428fa9b9527ab63a9908): perf score=1.000000
I20260812 06:18:13.619994 25707 maintenance_manager.cc:643] P 54fbcfe96d6d47bb930c301ac4fb0790: MajorDeltaCompactionOp(eb19157d8268428fa9b9527ab63a9908) complete. Timing: real 0.132s	user 0.113s	sys 0.017s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":876,"lbm_read_time_us":9383,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25731,"lbm_writes_lt_1ms":443,"mutex_wait_us":85,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":13312,"update_count":2000}
I20260812 06:18:13.620648 25777 maintenance_manager.cc:419] P 54fbcfe96d6d47bb930c301ac4fb0790: Scheduling FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908): perf score=10.126437
I20260812 06:18:13.672010 25707 maintenance_manager.cc:643] P 54fbcfe96d6d47bb930c301ac4fb0790: FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908) complete. Timing: real 0.051s	user 0.018s	sys 0.023s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":13470,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:13.672787 25777 maintenance_manager.cc:419] P 54fbcfe96d6d47bb930c301ac4fb0790: Scheduling FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908): perf score=2.188937
I20260812 06:18:13.690003 25707 maintenance_manager.cc:643] P 54fbcfe96d6d47bb930c301ac4fb0790: FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908) complete. Timing: real 0.017s	user 0.010s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6310,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:13.690764 25777 maintenance_manager.cc:419] P 54fbcfe96d6d47bb930c301ac4fb0790: Scheduling FlushMRSOp(eb19157d8268428fa9b9527ab63a9908): perf score=1.000000
I20260812 06:18:13.733635 25707 maintenance_manager.cc:643] P 54fbcfe96d6d47bb930c301ac4fb0790: FlushMRSOp(eb19157d8268428fa9b9527ab63a9908) complete. Timing: real 0.043s	user 0.027s	sys 0.003s Metrics: {"bytes_written":1152510,"cfile_init":1,"dirs.queue_time_us":95,"dirs.run_cpu_time_us":193,"dirs.run_wall_time_us":1750,"drs_written":1,"lbm_read_time_us":63,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2018,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:13.734601 25777 maintenance_manager.cc:419] P 54fbcfe96d6d47bb930c301ac4fb0790: Scheduling LogGCOp(eb19157d8268428fa9b9527ab63a9908): free 112692558 bytes of WAL
I20260812 06:18:13.734953 25707 log_reader.cc:385] T eb19157d8268428fa9b9527ab63a9908: removed 11 log segments from log reader
I20260812 06:18:13.735044 25707 log.cc:1079] T eb19157d8268428fa9b9527ab63a9908 P 54fbcfe96d6d47bb930c301ac4fb0790: Deleting log segment in path: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515488796982-25591-0/minicluster-data/ts-0-root/wals/eb19157d8268428fa9b9527ab63a9908/wal-000000028 (ops 133-137)
I20260812 06:18:13.735102 25707 log.cc:1079] T eb19157d8268428fa9b9527ab63a9908 P 54fbcfe96d6d47bb930c301ac4fb0790: Deleting log segment in path: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515488796982-25591-0/minicluster-data/ts-0-root/wals/eb19157d8268428fa9b9527ab63a9908/wal-000000029 (ops 138-142)
I20260812 06:18:13.735186 25707 log.cc:1079] T eb19157d8268428fa9b9527ab63a9908 P 54fbcfe96d6d47bb930c301ac4fb0790: Deleting log segment in path: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515488796982-25591-0/minicluster-data/ts-0-root/wals/eb19157d8268428fa9b9527ab63a9908/wal-000000030 (ops 143-147)
I20260812 06:18:13.735244 25707 log.cc:1079] T eb19157d8268428fa9b9527ab63a9908 P 54fbcfe96d6d47bb930c301ac4fb0790: Deleting log segment in path: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515488796982-25591-0/minicluster-data/ts-0-root/wals/eb19157d8268428fa9b9527ab63a9908/wal-000000031 (ops 148-152)
I20260812 06:18:13.735284 25707 log.cc:1079] T eb19157d8268428fa9b9527ab63a9908 P 54fbcfe96d6d47bb930c301ac4fb0790: Deleting log segment in path: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515488796982-25591-0/minicluster-data/ts-0-root/wals/eb19157d8268428fa9b9527ab63a9908/wal-000000032 (ops 153-157)
I20260812 06:18:13.735324 25707 log.cc:1079] T eb19157d8268428fa9b9527ab63a9908 P 54fbcfe96d6d47bb930c301ac4fb0790: Deleting log segment in path: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515488796982-25591-0/minicluster-data/ts-0-root/wals/eb19157d8268428fa9b9527ab63a9908/wal-000000033 (ops 158-162)
I20260812 06:18:13.735363 25707 log.cc:1079] T eb19157d8268428fa9b9527ab63a9908 P 54fbcfe96d6d47bb930c301ac4fb0790: Deleting log segment in path: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515488796982-25591-0/minicluster-data/ts-0-root/wals/eb19157d8268428fa9b9527ab63a9908/wal-000000034 (ops 163-167)
I20260812 06:18:13.735409 25707 log.cc:1079] T eb19157d8268428fa9b9527ab63a9908 P 54fbcfe96d6d47bb930c301ac4fb0790: Deleting log segment in path: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515488796982-25591-0/minicluster-data/ts-0-root/wals/eb19157d8268428fa9b9527ab63a9908/wal-000000035 (ops 168-172)
I20260812 06:18:13.735433 25707 log.cc:1079] T eb19157d8268428fa9b9527ab63a9908 P 54fbcfe96d6d47bb930c301ac4fb0790: Deleting log segment in path: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515488796982-25591-0/minicluster-data/ts-0-root/wals/eb19157d8268428fa9b9527ab63a9908/wal-000000036 (ops 173-177)
I20260812 06:18:13.735463 25707 log.cc:1079] T eb19157d8268428fa9b9527ab63a9908 P 54fbcfe96d6d47bb930c301ac4fb0790: Deleting log segment in path: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515488796982-25591-0/minicluster-data/ts-0-root/wals/eb19157d8268428fa9b9527ab63a9908/wal-000000037 (ops 178-182)
I20260812 06:18:13.735507 25707 log.cc:1079] T eb19157d8268428fa9b9527ab63a9908 P 54fbcfe96d6d47bb930c301ac4fb0790: Deleting log segment in path: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515488796982-25591-0/minicluster-data/ts-0-root/wals/eb19157d8268428fa9b9527ab63a9908/wal-000000038 (ops 183-187)
I20260812 06:18:13.759536 25707 maintenance_manager.cc:643] P 54fbcfe96d6d47bb930c301ac4fb0790: LogGCOp(eb19157d8268428fa9b9527ab63a9908) complete. Timing: real 0.025s	user 0.000s	sys 0.021s Metrics: {}
I20260812 06:18:13.760078 25777 maintenance_manager.cc:419] P 54fbcfe96d6d47bb930c301ac4fb0790: Scheduling UndoDeltaBlockGCOp(eb19157d8268428fa9b9527ab63a9908): 448 bytes on disk
I20260812 06:18:13.760540 25707 maintenance_manager.cc:643] P 54fbcfe96d6d47bb930c301ac4fb0790: UndoDeltaBlockGCOp(eb19157d8268428fa9b9527ab63a9908) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4}
I20260812 06:18:13.761083 25777 maintenance_manager.cc:419] P 54fbcfe96d6d47bb930c301ac4fb0790: Scheduling FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908): perf score=3.181125
I20260812 06:18:13.787655 25707 maintenance_manager.cc:643] P 54fbcfe96d6d47bb930c301ac4fb0790: FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908) complete. Timing: real 0.026s	user 0.012s	sys 0.004s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":7100,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:13.788249 25777 maintenance_manager.cc:419] P 54fbcfe96d6d47bb930c301ac4fb0790: Scheduling FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908): perf score=2.188937
I20260812 06:18:13.798759 25707 maintenance_manager.cc:643] P 54fbcfe96d6d47bb930c301ac4fb0790: FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4042,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:13.799288 25777 maintenance_manager.cc:419] P 54fbcfe96d6d47bb930c301ac4fb0790: Scheduling MajorDeltaCompactionOp(eb19157d8268428fa9b9527ab63a9908): perf score=1.000000
I20260812 06:18:14.012104 25707 maintenance_manager.cc:643] P 54fbcfe96d6d47bb930c301ac4fb0790: MajorDeltaCompactionOp(eb19157d8268428fa9b9527ab63a9908) complete. Timing: real 0.213s	user 0.149s	sys 0.063s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877330,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":559,"lbm_read_time_us":14172,"lbm_reads_lt_1ms":674,"lbm_write_time_us":35338,"lbm_writes_lt_1ms":643,"mutex_wait_us":48,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":2816,"thread_start_us":73,"threads_started":1,"update_count":3000}
I20260812 06:18:14.012959 25777 maintenance_manager.cc:419] P 54fbcfe96d6d47bb930c301ac4fb0790: Scheduling FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908): perf score=14.095187
I20260812 06:18:14.093072 25707 maintenance_manager.cc:643] P 54fbcfe96d6d47bb930c301ac4fb0790: FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908) complete. Timing: real 0.080s	user 0.036s	sys 0.028s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":30578,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:18:14.093652 25777 maintenance_manager.cc:419] P 54fbcfe96d6d47bb930c301ac4fb0790: Scheduling FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908): perf score=2.188937
I20260812 06:18:14.104341 25707 maintenance_manager.cc:643] P 54fbcfe96d6d47bb930c301ac4fb0790: FlushDeltaMemStoresOp(eb19157d8268428fa9b9527ab63a9908) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3995,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:14.104866 25777 maintenance_manager.cc:419] P 54fbcfe96d6d47bb930c301ac4fb0790: Scheduling MajorDeltaCompactionOp(eb19157d8268428fa9b9527ab63a9908): perf score=1.000000
I20260812 06:18:14.141999 25591 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.030s	user 1.824s	sys 0.176s
I20260812 06:18:14.201916 25591 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.059s	user 0.001s	sys 0.000s
I20260812 06:18:14.202587 25591 tablet_server.cc:179] TabletServer@127.24.253.193:0 shutting down...
I20260812 06:18:14.252475 25707 maintenance_manager.cc:643] P 54fbcfe96d6d47bb930c301ac4fb0790: MajorDeltaCompactionOp(eb19157d8268428fa9b9527ab63a9908) complete. Timing: real 0.147s	user 0.093s	sys 0.054s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":547,"lbm_read_time_us":11762,"lbm_reads_lt_1ms":568,"lbm_write_time_us":25016,"lbm_writes_lt_1ms":543,"mutex_wait_us":82,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14208,"update_count":2500}
I20260812 06:18:14.253274 25591 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:14.253657 25591 tablet_replica.cc:333] T eb19157d8268428fa9b9527ab63a9908 P 54fbcfe96d6d47bb930c301ac4fb0790: stopping tablet replica
I20260812 06:18:14.253899 25591 raft_consensus.cc:2243] T eb19157d8268428fa9b9527ab63a9908 P 54fbcfe96d6d47bb930c301ac4fb0790 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:14.254150 25591 raft_consensus.cc:2272] T eb19157d8268428fa9b9527ab63a9908 P 54fbcfe96d6d47bb930c301ac4fb0790 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:14.271955 25591 tablet_server.cc:196] TabletServer@127.24.253.193:0 shutdown complete.
I20260812 06:18:14.302094 25591 master.cc:562] Master@127.24.253.254:38683 shutting down...
I20260812 06:18:14.306766 25591 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 6f7bd8e0cc064a50b87a6defa014d072 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:14.306969 25591 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 6f7bd8e0cc064a50b87a6defa014d072 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:14.307158 25591 tablet_replica.cc:333] T 00000000000000000000000000000000 P 6f7bd8e0cc064a50b87a6defa014d072: stopping tablet replica
I20260812 06:18:14.319978 25591 master.cc:584] Master@127.24.253.254:38683 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5599 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:18:14.418249 25591 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.24.253.254:39663
I20260812 06:18:14.418718 25591 file_cache.cc:504] Constructed file cache file cache with capacity 419430
I20260812 06:18:14.421627 25591 server_base.cc:1061] running on GCE node
W20260812 06:18:14.421573 25812 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:18:14.421559 25809 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:18:14.421590 25810 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:18:14.422060 25591 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:14.422129 25591 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:18:14.422153 25591 hybrid_clock.cc:648] HybridClock initialized: now 1786515494422152 us; error 0 us; skew 500 ppm
I20260812 06:18:14.423063 25591 webserver.cc:533] Webserver started at http://127.24.253.254:43913/ using document root <none> and password file <none>
I20260812 06:18:14.423257 25591 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:14.423331 25591 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:14.423413 25591 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:14.423893 25591 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515488796982-25591-0/minicluster-data/master-0-root/instance:
uuid: "59c96fd322bc48118db776e1f3fc2384"
format_stamp: "Formatted at 2026-08-12 06:18:14 on dist-test-slave-mvvj"
I20260812 06:18:14.425549 25591 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:14.426580 25817 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:18:14.426910 25591 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:14.427006 25591 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515488796982-25591-0/minicluster-data/master-0-root
uuid: "59c96fd322bc48118db776e1f3fc2384"
format_stamp: "Formatted at 2026-08-12 06:18:14 on dist-test-slave-mvvj"
I20260812 06:18:14.427105 25591 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515488796982-25591-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515488796982-25591-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515488796982-25591-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:18:14.434648 25591 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:14.435086 25591 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:14.439601 25591 rpc_server.cc:307] RPC server started. Bound to: 127.24.253.254:39663
I20260812 06:18:14.441340 25880 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:18:14.444796 25879 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.24.253.254:39663 every 8 connection(s)
I20260812 06:18:14.445813 25880 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 59c96fd322bc48118db776e1f3fc2384: Bootstrap starting.
I20260812 06:18:14.446637 25880 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 59c96fd322bc48118db776e1f3fc2384: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:14.447718 25880 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 59c96fd322bc48118db776e1f3fc2384: No bootstrap required, opened a new log
I20260812 06:18:14.448174 25880 raft_consensus.cc:359] T 00000000000000000000000000000000 P 59c96fd322bc48118db776e1f3fc2384 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "59c96fd322bc48118db776e1f3fc2384" member_type: VOTER }
I20260812 06:18:14.448267 25880 raft_consensus.cc:385] T 00000000000000000000000000000000 P 59c96fd322bc48118db776e1f3fc2384 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:14.448290 25880 raft_consensus.cc:740] T 00000000000000000000000000000000 P 59c96fd322bc48118db776e1f3fc2384 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 59c96fd322bc48118db776e1f3fc2384, State: Initialized, Role: FOLLOWER
I20260812 06:18:14.448441 25880 consensus_queue.cc:260] T 00000000000000000000000000000000 P 59c96fd322bc48118db776e1f3fc2384 [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: "59c96fd322bc48118db776e1f3fc2384" member_type: VOTER }
I20260812 06:18:14.448540 25880 raft_consensus.cc:399] T 00000000000000000000000000000000 P 59c96fd322bc48118db776e1f3fc2384 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:14.448566 25880 raft_consensus.cc:493] T 00000000000000000000000000000000 P 59c96fd322bc48118db776e1f3fc2384 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:14.448596 25880 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 59c96fd322bc48118db776e1f3fc2384 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:14.449260 25880 raft_consensus.cc:515] T 00000000000000000000000000000000 P 59c96fd322bc48118db776e1f3fc2384 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "59c96fd322bc48118db776e1f3fc2384" member_type: VOTER }
I20260812 06:18:14.449375 25880 leader_election.cc:304] T 00000000000000000000000000000000 P 59c96fd322bc48118db776e1f3fc2384 [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: 59c96fd322bc48118db776e1f3fc2384; no voters: 
I20260812 06:18:14.449538 25880 leader_election.cc:290] T 00000000000000000000000000000000 P 59c96fd322bc48118db776e1f3fc2384 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:14.449725 25884 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 59c96fd322bc48118db776e1f3fc2384 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:14.449975 25884 raft_consensus.cc:697] T 00000000000000000000000000000000 P 59c96fd322bc48118db776e1f3fc2384 [term 1 LEADER]: Becoming Leader. State: Replica: 59c96fd322bc48118db776e1f3fc2384, State: Running, Role: LEADER
I20260812 06:18:14.449999 25880 sys_catalog.cc:565] T 00000000000000000000000000000000 P 59c96fd322bc48118db776e1f3fc2384 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:14.450170 25884 consensus_queue.cc:237] T 00000000000000000000000000000000 P 59c96fd322bc48118db776e1f3fc2384 [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: "59c96fd322bc48118db776e1f3fc2384" member_type: VOTER }
I20260812 06:18:14.450734 25886 sys_catalog.cc:455] T 00000000000000000000000000000000 P 59c96fd322bc48118db776e1f3fc2384 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 59c96fd322bc48118db776e1f3fc2384. Latest consensus state: current_term: 1 leader_uuid: "59c96fd322bc48118db776e1f3fc2384" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "59c96fd322bc48118db776e1f3fc2384" member_type: VOTER } }
I20260812 06:18:14.450917 25886 sys_catalog.cc:458] T 00000000000000000000000000000000 P 59c96fd322bc48118db776e1f3fc2384 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:14.451056 25885 sys_catalog.cc:455] T 00000000000000000000000000000000 P 59c96fd322bc48118db776e1f3fc2384 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "59c96fd322bc48118db776e1f3fc2384" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "59c96fd322bc48118db776e1f3fc2384" member_type: VOTER } }
I20260812 06:18:14.451145 25885 sys_catalog.cc:458] T 00000000000000000000000000000000 P 59c96fd322bc48118db776e1f3fc2384 [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:14.451551 25894 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:14.452366 25894 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:14.452634 25591 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:14.454418 25894 catalog_manager.cc:1383] Generated new cluster ID: 762871d3dbaf418ca8474538700b8f68
I20260812 06:18:14.454485 25894 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:14.470376 25894 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:14.471040 25894 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:14.479709 25894 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 59c96fd322bc48118db776e1f3fc2384: Generated new TSK 0
I20260812 06:18:14.479997 25894 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:14.485036 25591 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:14.487345 25904 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:18:14.487404 25903 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:18:14.487509 25906 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:18:14.487553 25591 server_base.cc:1061] running on GCE node
I20260812 06:18:14.487799 25591 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:14.487895 25591 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:18:14.487924 25591 hybrid_clock.cc:648] HybridClock initialized: now 1786515494487924 us; error 0 us; skew 500 ppm
I20260812 06:18:14.488790 25591 webserver.cc:533] Webserver started at http://127.24.253.193:36151/ using document root <none> and password file <none>
I20260812 06:18:14.488953 25591 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:14.488999 25591 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:14.489053 25591 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:14.489409 25591 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515488796982-25591-0/minicluster-data/ts-0-root/instance:
uuid: "bfaa0960a398435dace372671a2cd854"
format_stamp: "Formatted at 2026-08-12 06:18:14 on dist-test-slave-mvvj"
I20260812 06:18:14.490841 25591 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:18:14.491727 25911 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:18:14.491988 25591 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:18:14.492084 25591 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515488796982-25591-0/minicluster-data/ts-0-root
uuid: "bfaa0960a398435dace372671a2cd854"
format_stamp: "Formatted at 2026-08-12 06:18:14 on dist-test-slave-mvvj"
I20260812 06:18:14.492177 25591 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515488796982-25591-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515488796982-25591-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515488796982-25591-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:18:14.507397 25591 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:14.507992 25591 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:14.508288 25591 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:14.508771 25591 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:14.508832 25591 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:14.508951 25591 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:14.509008 25591 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:14.513670 25591 rpc_server.cc:307] RPC server started. Bound to: 127.24.253.193:42535
I20260812 06:18:14.514184 25982 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.24.253.193:42535 every 8 connection(s)
I20260812 06:18:14.519470 25983 heartbeater.cc:344] Connected to a master server at 127.24.253.254:39663
I20260812 06:18:14.519584 25983 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:14.519779 25983 heartbeater.cc:507] Master 127.24.253.254:39663 requested a full tablet report, sending...
I20260812 06:18:14.520628 25837 ts_manager.cc:194] Registered new tserver with Master: bfaa0960a398435dace372671a2cd854 (127.24.253.193:42535)
I20260812 06:18:14.521106 25591 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.006752401s
I20260812 06:18:14.521382 25837 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:60390
I20260812 06:18:14.529234 25837 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:60398:
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:18:14.538988 25942 tablet_service.cc:1511] Processing CreateTablet for tablet 1a878e8b99674902be2730f412e72085 (DEFAULT_TABLE table=heavy-update-compaction-test [id=d9d6b106785c4364b0d81f71b9488807]), partition=
I20260812 06:18:14.539325 25942 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 1a878e8b99674902be2730f412e72085. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:14.541783 25997 tablet_bootstrap.cc:492] T 1a878e8b99674902be2730f412e72085 P bfaa0960a398435dace372671a2cd854: Bootstrap starting.
I20260812 06:18:14.542759 25997 tablet_bootstrap.cc:654] T 1a878e8b99674902be2730f412e72085 P bfaa0960a398435dace372671a2cd854: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:14.543936 25997 tablet_bootstrap.cc:492] T 1a878e8b99674902be2730f412e72085 P bfaa0960a398435dace372671a2cd854: No bootstrap required, opened a new log
I20260812 06:18:14.544013 25997 ts_tablet_manager.cc:1403] T 1a878e8b99674902be2730f412e72085 P bfaa0960a398435dace372671a2cd854: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:18:14.544572 25997 raft_consensus.cc:359] T 1a878e8b99674902be2730f412e72085 P bfaa0960a398435dace372671a2cd854 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "bfaa0960a398435dace372671a2cd854" member_type: VOTER last_known_addr { host: "127.24.253.193" port: 42535 } }
I20260812 06:18:14.544687 25997 raft_consensus.cc:385] T 1a878e8b99674902be2730f412e72085 P bfaa0960a398435dace372671a2cd854 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:14.544732 25997 raft_consensus.cc:740] T 1a878e8b99674902be2730f412e72085 P bfaa0960a398435dace372671a2cd854 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: bfaa0960a398435dace372671a2cd854, State: Initialized, Role: FOLLOWER
I20260812 06:18:14.544878 25997 consensus_queue.cc:260] T 1a878e8b99674902be2730f412e72085 P bfaa0960a398435dace372671a2cd854 [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: "bfaa0960a398435dace372671a2cd854" member_type: VOTER last_known_addr { host: "127.24.253.193" port: 42535 } }
I20260812 06:18:14.544976 25997 raft_consensus.cc:399] T 1a878e8b99674902be2730f412e72085 P bfaa0960a398435dace372671a2cd854 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:14.545017 25997 raft_consensus.cc:493] T 1a878e8b99674902be2730f412e72085 P bfaa0960a398435dace372671a2cd854 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:14.545073 25997 raft_consensus.cc:3060] T 1a878e8b99674902be2730f412e72085 P bfaa0960a398435dace372671a2cd854 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:14.545864 25997 raft_consensus.cc:515] T 1a878e8b99674902be2730f412e72085 P bfaa0960a398435dace372671a2cd854 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "bfaa0960a398435dace372671a2cd854" member_type: VOTER last_known_addr { host: "127.24.253.193" port: 42535 } }
I20260812 06:18:14.546016 25997 leader_election.cc:304] T 1a878e8b99674902be2730f412e72085 P bfaa0960a398435dace372671a2cd854 [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: bfaa0960a398435dace372671a2cd854; no voters: 
I20260812 06:18:14.546242 25997 leader_election.cc:290] T 1a878e8b99674902be2730f412e72085 P bfaa0960a398435dace372671a2cd854 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:14.546399 25999 raft_consensus.cc:2804] T 1a878e8b99674902be2730f412e72085 P bfaa0960a398435dace372671a2cd854 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:14.546586 25997 ts_tablet_manager.cc:1434] T 1a878e8b99674902be2730f412e72085 P bfaa0960a398435dace372671a2cd854: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:18:14.546600 25983 heartbeater.cc:499] Master 127.24.253.254:39663 was elected leader, sending a full tablet report...
I20260812 06:18:14.546715 25999 raft_consensus.cc:697] T 1a878e8b99674902be2730f412e72085 P bfaa0960a398435dace372671a2cd854 [term 1 LEADER]: Becoming Leader. State: Replica: bfaa0960a398435dace372671a2cd854, State: Running, Role: LEADER
I20260812 06:18:14.546840 25999 consensus_queue.cc:237] T 1a878e8b99674902be2730f412e72085 P bfaa0960a398435dace372671a2cd854 [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: "bfaa0960a398435dace372671a2cd854" member_type: VOTER last_known_addr { host: "127.24.253.193" port: 42535 } }
I20260812 06:18:14.548280 25837 catalog_manager.cc:5719] T 1a878e8b99674902be2730f412e72085 P bfaa0960a398435dace372671a2cd854 reported cstate change: term changed from 0 to 1, leader changed from <none> to bfaa0960a398435dace372671a2cd854 (127.24.253.193). New cstate: current_term: 1 leader_uuid: "bfaa0960a398435dace372671a2cd854" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "bfaa0960a398435dace372671a2cd854" member_type: VOTER last_known_addr { host: "127.24.253.193" port: 42535 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:14.608057 25591 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.053s	user 0.014s	sys 0.008s
I20260812 06:18:14.764926 25984 maintenance_manager.cc:419] P bfaa0960a398435dace372671a2cd854: Scheduling FlushMRSOp(1a878e8b99674902be2730f412e72085): perf score=19.054940
I20260812 06:18:14.920099 25916 maintenance_manager.cc:643] P bfaa0960a398435dace372671a2cd854: FlushMRSOp(1a878e8b99674902be2730f412e72085) complete. Timing: real 0.155s	user 0.099s	sys 0.056s Metrics: {"bytes_written":12307490,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":76,"dirs.run_cpu_time_us":212,"dirs.run_wall_time_us":920,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":38270,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1500}
I20260812 06:18:14.920876 25984 maintenance_manager.cc:419] P bfaa0960a398435dace372671a2cd854: Scheduling LogGCOp(1a878e8b99674902be2730f412e72085): free 20743880 bytes of WAL
I20260812 06:18:14.921129 25916 log_reader.cc:385] T 1a878e8b99674902be2730f412e72085: removed 2 log segments from log reader
I20260812 06:18:14.921180 25916 log.cc:1079] T 1a878e8b99674902be2730f412e72085 P bfaa0960a398435dace372671a2cd854: Deleting log segment in path: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515488796982-25591-0/minicluster-data/ts-0-root/wals/1a878e8b99674902be2730f412e72085/wal-000000001 (ops 1-6)
I20260812 06:18:14.921212 25916 log.cc:1079] T 1a878e8b99674902be2730f412e72085 P bfaa0960a398435dace372671a2cd854: Deleting log segment in path: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515488796982-25591-0/minicluster-data/ts-0-root/wals/1a878e8b99674902be2730f412e72085/wal-000000002 (ops 7-11)
I20260812 06:18:14.925513 25916 maintenance_manager.cc:643] P bfaa0960a398435dace372671a2cd854: LogGCOp(1a878e8b99674902be2730f412e72085) complete. Timing: real 0.004s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:18:14.925907 25984 maintenance_manager.cc:419] P bfaa0960a398435dace372671a2cd854: Scheduling UndoDeltaBlockGCOp(1a878e8b99674902be2730f412e72085): 16411392 bytes on disk
I20260812 06:18:14.926379 25916 maintenance_manager.cc:643] P bfaa0960a398435dace372671a2cd854: UndoDeltaBlockGCOp(1a878e8b99674902be2730f412e72085) 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:18:14.926844 25984 maintenance_manager.cc:419] P bfaa0960a398435dace372671a2cd854: Scheduling FlushDeltaMemStoresOp(1a878e8b99674902be2730f412e72085): perf score=2.188937
I20260812 06:18:14.939534 25916 maintenance_manager.cc:643] P bfaa0960a398435dace372671a2cd854: FlushDeltaMemStoresOp(1a878e8b99674902be2730f412e72085) complete. Timing: real 0.013s	user 0.003s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4511,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:14.940037 25984 maintenance_manager.cc:419] P bfaa0960a398435dace372671a2cd854: Scheduling MajorDeltaCompactionOp(1a878e8b99674902be2730f412e72085): perf score=1.000000
I20260812 06:18:15.106856 25916 maintenance_manager.cc:643] P bfaa0960a398435dace372671a2cd854: MajorDeltaCompactionOp(1a878e8b99674902be2730f412e72085) complete. Timing: real 0.167s	user 0.093s	sys 0.061s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":552,"lbm_read_time_us":9490,"lbm_reads_lt_1ms":460,"lbm_write_time_us":24672,"lbm_writes_lt_1ms":443,"mutex_wait_us":27,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":35840,"thread_start_us":337,"threads_started":5,"update_count":2000}
I20260812 06:18:15.107455 25984 maintenance_manager.cc:419] P bfaa0960a398435dace372671a2cd854: Scheduling FlushDeltaMemStoresOp(1a878e8b99674902be2730f412e72085): perf score=14.095187
I20260812 06:18:15.165562 25916 maintenance_manager.cc:643] P bfaa0960a398435dace372671a2cd854: FlushDeltaMemStoresOp(1a878e8b99674902be2730f412e72085) complete. Timing: real 0.058s	user 0.041s	sys 0.015s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":25641,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:15.166117 25984 maintenance_manager.cc:419] P bfaa0960a398435dace372671a2cd854: Scheduling FlushDeltaMemStoresOp(1a878e8b99674902be2730f412e72085): perf score=2.188937
I20260812 06:18:15.188772 25916 maintenance_manager.cc:643] P bfaa0960a398435dace372671a2cd854: FlushDeltaMemStoresOp(1a878e8b99674902be2730f412e72085) complete. Timing: real 0.022s	user 0.010s	sys 0.011s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4228,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:15.189301 25984 maintenance_manager.cc:419] P bfaa0960a398435dace372671a2cd854: Scheduling MajorDeltaCompactionOp(1a878e8b99674902be2730f412e72085): perf score=1.000000
I20260812 06:18:15.382638 25916 maintenance_manager.cc:643] P bfaa0960a398435dace372671a2cd854: MajorDeltaCompactionOp(1a878e8b99674902be2730f412e72085) complete. Timing: real 0.193s	user 0.125s	sys 0.068s 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":221,"lbm_read_time_us":11821,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33415,"lbm_writes_lt_1ms":543,"mutex_wait_us":39,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6016,"update_count":2500}
I20260812 06:18:15.383376 25984 maintenance_manager.cc:419] P bfaa0960a398435dace372671a2cd854: Scheduling FlushDeltaMemStoresOp(1a878e8b99674902be2730f412e72085): perf score=14.095187
I20260812 06:18:15.442420 25916 maintenance_manager.cc:643] P bfaa0960a398435dace372671a2cd854: FlushDeltaMemStoresOp(1a878e8b99674902be2730f412e72085) complete. Timing: real 0.059s	user 0.011s	sys 0.037s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22828,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2000}
I20260812 06:18:15.442957 25984 maintenance_manager.cc:419] P bfaa0960a398435dace372671a2cd854: Scheduling FlushDeltaMemStoresOp(1a878e8b99674902be2730f412e72085): perf score=2.188937
I20260812 06:18:15.456156 25916 maintenance_manager.cc:643] P bfaa0960a398435dace372671a2cd854: FlushDeltaMemStoresOp(1a878e8b99674902be2730f412e72085) complete. Timing: real 0.013s	user 0.005s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4792,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:15.457119 25984 maintenance_manager.cc:419] P bfaa0960a398435dace372671a2cd854: Scheduling MajorDeltaCompactionOp(1a878e8b99674902be2730f412e72085): perf score=1.000000
I20260812 06:18:15.659039 25916 maintenance_manager.cc:643] P bfaa0960a398435dace372671a2cd854: MajorDeltaCompactionOp(1a878e8b99674902be2730f412e72085) complete. Timing: real 0.202s	user 0.142s	sys 0.049s 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":1140,"lbm_read_time_us":11251,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34021,"lbm_writes_lt_1ms":543,"mutex_wait_us":100,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11904,"update_count":2500}
I20260812 06:18:15.659780 25984 maintenance_manager.cc:419] P bfaa0960a398435dace372671a2cd854: Scheduling FlushDeltaMemStoresOp(1a878e8b99674902be2730f412e72085): perf score=14.095187
I20260812 06:18:15.713383 25916 maintenance_manager.cc:643] P bfaa0960a398435dace372671a2cd854: FlushDeltaMemStoresOp(1a878e8b99674902be2730f412e72085) complete. Timing: real 0.053s	user 0.031s	sys 0.016s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":21282,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:15.713979 25984 maintenance_manager.cc:419] P bfaa0960a398435dace372671a2cd854: Scheduling FlushDeltaMemStoresOp(1a878e8b99674902be2730f412e72085): perf score=2.188937
I20260812 06:18:15.725657 25916 maintenance_manager.cc:643] P bfaa0960a398435dace372671a2cd854: FlushDeltaMemStoresOp(1a878e8b99674902be2730f412e72085) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4191,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:15.726150 25984 maintenance_manager.cc:419] P bfaa0960a398435dace372671a2cd854: Scheduling MajorDeltaCompactionOp(1a878e8b99674902be2730f412e72085): perf score=1.000000
I20260812 06:18:15.880043 25916 maintenance_manager.cc:643] P bfaa0960a398435dace372671a2cd854: MajorDeltaCompactionOp(1a878e8b99674902be2730f412e72085) complete. Timing: real 0.154s	user 0.102s	sys 0.043s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774692,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":622,"lbm_read_time_us":9850,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28758,"lbm_writes_lt_1ms":543,"mutex_wait_us":263,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:18:15.880616 25984 maintenance_manager.cc:419] P bfaa0960a398435dace372671a2cd854: Scheduling FlushDeltaMemStoresOp(1a878e8b99674902be2730f412e72085): perf score=11.118625
I20260812 06:18:15.917497 25916 maintenance_manager.cc:643] P bfaa0960a398435dace372671a2cd854: FlushDeltaMemStoresOp(1a878e8b99674902be2730f412e72085) complete. Timing: real 0.037s	user 0.018s	sys 0.016s Metrics: {"bytes_written":13415136,"delete_count":0,"lbm_write_time_us":14464,"lbm_writes_lt_1ms":330,"reinsert_count":0,"update_count":1635}
I20260812 06:18:15.918403 25984 maintenance_manager.cc:419] P bfaa0960a398435dace372671a2cd854: Scheduling FlushDeltaMemStoresOp(1a878e8b99674902be2730f412e72085): perf score=1.196750
I20260812 06:18:15.932399 25916 maintenance_manager.cc:643] P bfaa0960a398435dace372671a2cd854: FlushDeltaMemStoresOp(1a878e8b99674902be2730f412e72085) complete. Timing: real 0.014s	user 0.012s	sys 0.000s Metrics: {"bytes_written":2994980,"delete_count":0,"lbm_write_time_us":4660,"lbm_writes_lt_1ms":76,"reinsert_count":0,"update_count":365}
I20260812 06:18:15.933010 25984 maintenance_manager.cc:419] P bfaa0960a398435dace372671a2cd854: Scheduling MajorDeltaCompactionOp(1a878e8b99674902be2730f412e72085): perf score=1.000000
I20260812 06:18:16.074960 25916 maintenance_manager.cc:643] P bfaa0960a398435dace372671a2cd854: MajorDeltaCompactionOp(1a878e8b99674902be2730f412e72085) complete. Timing: real 0.142s	user 0.114s	sys 0.027s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672244,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":505,"lbm_read_time_us":7900,"lbm_reads_lt_1ms":464,"lbm_write_time_us":27039,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2000}
I20260812 06:18:16.075927 25984 maintenance_manager.cc:419] P bfaa0960a398435dace372671a2cd854: Scheduling FlushDeltaMemStoresOp(1a878e8b99674902be2730f412e72085): perf score=11.118625
I20260812 06:18:16.121251 25916 maintenance_manager.cc:643] P bfaa0960a398435dace372671a2cd854: FlushDeltaMemStoresOp(1a878e8b99674902be2730f412e72085) complete. Timing: real 0.045s	user 0.027s	sys 0.017s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":19959,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:16.121758 25984 maintenance_manager.cc:419] P bfaa0960a398435dace372671a2cd854: Scheduling FlushDeltaMemStoresOp(1a878e8b99674902be2730f412e72085): perf score=2.188937
I20260812 06:18:16.136572 25916 maintenance_manager.cc:643] P bfaa0960a398435dace372671a2cd854: FlushDeltaMemStoresOp(1a878e8b99674902be2730f412e72085) complete. Timing: real 0.015s	user 0.006s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5678,"lbm_writes_lt_1ms":93,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":450}
I20260812 06:18:16.137072 25984 maintenance_manager.cc:419] P bfaa0960a398435dace372671a2cd854: Scheduling FlushMRSOp(1a878e8b99674902be2730f412e72085): perf score=1.000000
I20260812 06:18:16.167655 25916 maintenance_manager.cc:643] P bfaa0960a398435dace372671a2cd854: FlushMRSOp(1a878e8b99674902be2730f412e72085) complete. Timing: real 0.030s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":85,"dirs.run_cpu_time_us":210,"dirs.run_wall_time_us":1687,"drs_written":1,"lbm_read_time_us":43,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1654,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:16.168352 25984 maintenance_manager.cc:419] P bfaa0960a398435dace372671a2cd854: Scheduling LogGCOp(1a878e8b99674902be2730f412e72085): free 103925252 bytes of WAL
I20260812 06:18:16.168614 25916 log_reader.cc:385] T 1a878e8b99674902be2730f412e72085: removed 10 log segments from log reader
I20260812 06:18:16.168664 25916 log.cc:1079] T 1a878e8b99674902be2730f412e72085 P bfaa0960a398435dace372671a2cd854: Deleting log segment in path: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515488796982-25591-0/minicluster-data/ts-0-root/wals/1a878e8b99674902be2730f412e72085/wal-000000003 (ops 12-16)
I20260812 06:18:16.168700 25916 log.cc:1079] T 1a878e8b99674902be2730f412e72085 P bfaa0960a398435dace372671a2cd854: Deleting log segment in path: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515488796982-25591-0/minicluster-data/ts-0-root/wals/1a878e8b99674902be2730f412e72085/wal-000000004 (ops 17-21)
I20260812 06:18:16.168766 25916 log.cc:1079] T 1a878e8b99674902be2730f412e72085 P bfaa0960a398435dace372671a2cd854: Deleting log segment in path: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515488796982-25591-0/minicluster-data/ts-0-root/wals/1a878e8b99674902be2730f412e72085/wal-000000005 (ops 22-26)
I20260812 06:18:16.168905 25916 log.cc:1079] T 1a878e8b99674902be2730f412e72085 P bfaa0960a398435dace372671a2cd854: Deleting log segment in path: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515488796982-25591-0/minicluster-data/ts-0-root/wals/1a878e8b99674902be2730f412e72085/wal-000000006 (ops 27-31)
I20260812 06:18:16.168972 25916 log.cc:1079] T 1a878e8b99674902be2730f412e72085 P bfaa0960a398435dace372671a2cd854: Deleting log segment in path: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515488796982-25591-0/minicluster-data/ts-0-root/wals/1a878e8b99674902be2730f412e72085/wal-000000007 (ops 32-36)
I20260812 06:18:16.169050 25916 log.cc:1079] T 1a878e8b99674902be2730f412e72085 P bfaa0960a398435dace372671a2cd854: Deleting log segment in path: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515488796982-25591-0/minicluster-data/ts-0-root/wals/1a878e8b99674902be2730f412e72085/wal-000000008 (ops 37-41)
I20260812 06:18:16.169112 25916 log.cc:1079] T 1a878e8b99674902be2730f412e72085 P bfaa0960a398435dace372671a2cd854: Deleting log segment in path: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515488796982-25591-0/minicluster-data/ts-0-root/wals/1a878e8b99674902be2730f412e72085/wal-000000009 (ops 42-46)
I20260812 06:18:16.169195 25916 log.cc:1079] T 1a878e8b99674902be2730f412e72085 P bfaa0960a398435dace372671a2cd854: Deleting log segment in path: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515488796982-25591-0/minicluster-data/ts-0-root/wals/1a878e8b99674902be2730f412e72085/wal-000000010 (ops 47-51)
I20260812 06:18:16.169265 25916 log.cc:1079] T 1a878e8b99674902be2730f412e72085 P bfaa0960a398435dace372671a2cd854: Deleting log segment in path: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515488796982-25591-0/minicluster-data/ts-0-root/wals/1a878e8b99674902be2730f412e72085/wal-000000011 (ops 52-56)
I20260812 06:18:16.169337 25916 log.cc:1079] T 1a878e8b99674902be2730f412e72085 P bfaa0960a398435dace372671a2cd854: Deleting log segment in path: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515488796982-25591-0/minicluster-data/ts-0-root/wals/1a878e8b99674902be2730f412e72085/wal-000000012 (ops 57-61)
I20260812 06:18:16.194814 25916 maintenance_manager.cc:643] P bfaa0960a398435dace372671a2cd854: LogGCOp(1a878e8b99674902be2730f412e72085) complete. Timing: real 0.026s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:18:16.195323 25984 maintenance_manager.cc:419] P bfaa0960a398435dace372671a2cd854: Scheduling UndoDeltaBlockGCOp(1a878e8b99674902be2730f412e72085): 447 bytes on disk
I20260812 06:18:16.196002 25916 maintenance_manager.cc:643] P bfaa0960a398435dace372671a2cd854: UndoDeltaBlockGCOp(1a878e8b99674902be2730f412e72085) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":73,"lbm_reads_lt_1ms":4}
I20260812 06:18:16.196578 25984 maintenance_manager.cc:419] P bfaa0960a398435dace372671a2cd854: Scheduling FlushDeltaMemStoresOp(1a878e8b99674902be2730f412e72085): perf score=3.181125
I20260812 06:18:16.214637 25916 maintenance_manager.cc:643] P bfaa0960a398435dace372671a2cd854: FlushDeltaMemStoresOp(1a878e8b99674902be2730f412e72085) complete. Timing: real 0.018s	user 0.009s	sys 0.007s Metrics: {"bytes_written":4964173,"delete_count":0,"lbm_write_time_us":7586,"lbm_writes_lt_1ms":124,"reinsert_count":0,"update_count":605}
I20260812 06:18:16.215080 25984 maintenance_manager.cc:419] P bfaa0960a398435dace372671a2cd854: Scheduling LogGCOp(1a878e8b99674902be2730f412e72085): free 8767123 bytes of WAL
I20260812 06:18:16.215289 25916 log_reader.cc:385] T 1a878e8b99674902be2730f412e72085: removed 1 log segments from log reader
I20260812 06:18:16.215334 25916 log.cc:1079] T 1a878e8b99674902be2730f412e72085 P bfaa0960a398435dace372671a2cd854: Deleting log segment in path: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515488796982-25591-0/minicluster-data/ts-0-root/wals/1a878e8b99674902be2730f412e72085/wal-000000013 (ops 62-66)
I20260812 06:18:16.217073 25916 maintenance_manager.cc:643] P bfaa0960a398435dace372671a2cd854: LogGCOp(1a878e8b99674902be2730f412e72085) complete. Timing: real 0.002s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:18:16.217377 25984 maintenance_manager.cc:419] P bfaa0960a398435dace372671a2cd854: Scheduling FlushDeltaMemStoresOp(1a878e8b99674902be2730f412e72085): perf score=2.188937
I20260812 06:18:16.227346 25916 maintenance_manager.cc:643] P bfaa0960a398435dace372671a2cd854: FlushDeltaMemStoresOp(1a878e8b99674902be2730f412e72085) complete. Timing: real 0.010s	user 0.006s	sys 0.001s Metrics: {"bytes_written":3241130,"delete_count":0,"lbm_write_time_us":3162,"lbm_writes_lt_1ms":82,"reinsert_count":0,"update_count":395}
I20260812 06:18:16.227964 25984 maintenance_manager.cc:419] P bfaa0960a398435dace372671a2cd854: Scheduling MajorDeltaCompactionOp(1a878e8b99674902be2730f412e72085): perf score=1.000000
I20260812 06:18:16.402195 25916 maintenance_manager.cc:643] P bfaa0960a398435dace372671a2cd854: MajorDeltaCompactionOp(1a878e8b99674902be2730f412e72085) complete. Timing: real 0.174s	user 0.148s	sys 0.025s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877315,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1841,"lbm_read_time_us":11940,"lbm_reads_lt_1ms":674,"lbm_write_time_us":33805,"lbm_writes_lt_1ms":643,"mutex_wait_us":679,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":87,"threads_started":1,"update_count":3000}
I20260812 06:18:16.402915 25984 maintenance_manager.cc:419] P bfaa0960a398435dace372671a2cd854: Scheduling FlushDeltaMemStoresOp(1a878e8b99674902be2730f412e72085): perf score=14.095187
I20260812 06:18:16.454435 25916 maintenance_manager.cc:643] P bfaa0960a398435dace372671a2cd854: FlushDeltaMemStoresOp(1a878e8b99674902be2730f412e72085) complete. Timing: real 0.051s	user 0.017s	sys 0.024s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":19937,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:16.454949 25984 maintenance_manager.cc:419] P bfaa0960a398435dace372671a2cd854: Scheduling FlushDeltaMemStoresOp(1a878e8b99674902be2730f412e72085): perf score=2.188937
I20260812 06:18:16.470504 25916 maintenance_manager.cc:643] P bfaa0960a398435dace372671a2cd854: FlushDeltaMemStoresOp(1a878e8b99674902be2730f412e72085) complete. Timing: real 0.015s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5736,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:16.471215 25984 maintenance_manager.cc:419] P bfaa0960a398435dace372671a2cd854: Scheduling MajorDeltaCompactionOp(1a878e8b99674902be2730f412e72085): perf score=1.000000
I20260812 06:18:16.628475 25916 maintenance_manager.cc:643] P bfaa0960a398435dace372671a2cd854: MajorDeltaCompactionOp(1a878e8b99674902be2730f412e72085) complete. Timing: real 0.157s	user 0.110s	sys 0.043s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":449,"lbm_read_time_us":11118,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28618,"lbm_writes_lt_1ms":543,"mutex_wait_us":80,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":127104,"update_count":2500}
I20260812 06:18:16.629119 25984 maintenance_manager.cc:419] P bfaa0960a398435dace372671a2cd854: Scheduling FlushDeltaMemStoresOp(1a878e8b99674902be2730f412e72085): perf score=11.118625
I20260812 06:18:16.676602 25916 maintenance_manager.cc:643] P bfaa0960a398435dace372671a2cd854: FlushDeltaMemStoresOp(1a878e8b99674902be2730f412e72085) complete. Timing: real 0.047s	user 0.030s	sys 0.016s Metrics: {"bytes_written":13210025,"delete_count":0,"lbm_write_time_us":19373,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":324,"reinsert_count":0,"update_count":1610}
I20260812 06:18:16.677107 25984 maintenance_manager.cc:419] P bfaa0960a398435dace372671a2cd854: Scheduling FlushDeltaMemStoresOp(1a878e8b99674902be2730f412e72085): perf score=2.188937
I20260812 06:18:16.697971 25916 maintenance_manager.cc:643] P bfaa0960a398435dace372671a2cd854: FlushDeltaMemStoresOp(1a878e8b99674902be2730f412e72085) complete. Timing: real 0.021s	user 0.000s	sys 0.008s Metrics: {"bytes_written":3200105,"delete_count":0,"lbm_write_time_us":3335,"lbm_writes_lt_1ms":81,"reinsert_count":0,"update_count":390}
I20260812 06:18:16.698462 25984 maintenance_manager.cc:419] P bfaa0960a398435dace372671a2cd854: Scheduling FlushDeltaMemStoresOp(1a878e8b99674902be2730f412e72085): perf score=2.188937
I20260812 06:18:16.709475 25916 maintenance_manager.cc:643] P bfaa0960a398435dace372671a2cd854: FlushDeltaMemStoresOp(1a878e8b99674902be2730f412e72085) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3955,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:16.710018 25984 maintenance_manager.cc:419] P bfaa0960a398435dace372671a2cd854: Scheduling MajorDeltaCompactionOp(1a878e8b99674902be2730f412e72085): perf score=1.000000
I20260812 06:18:16.886785 25916 maintenance_manager.cc:643] P bfaa0960a398435dace372671a2cd854: MajorDeltaCompactionOp(1a878e8b99674902be2730f412e72085) complete. Timing: real 0.177s	user 0.120s	sys 0.055s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774788,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":827,"lbm_read_time_us":11652,"lbm_reads_lt_1ms":573,"lbm_write_time_us":30136,"lbm_writes_lt_1ms":543,"mutex_wait_us":216,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9600,"update_count":2500}
I20260812 06:18:16.887442 25984 maintenance_manager.cc:419] P bfaa0960a398435dace372671a2cd854: Scheduling FlushDeltaMemStoresOp(1a878e8b99674902be2730f412e72085): perf score=14.095187
I20260812 06:18:16.950595 25916 maintenance_manager.cc:643] P bfaa0960a398435dace372671a2cd854: FlushDeltaMemStoresOp(1a878e8b99674902be2730f412e72085) complete. Timing: real 0.063s	user 0.025s	sys 0.024s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23332,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:16.951152 25984 maintenance_manager.cc:419] P bfaa0960a398435dace372671a2cd854: Scheduling FlushDeltaMemStoresOp(1a878e8b99674902be2730f412e72085): perf score=2.188937
I20260812 06:18:16.962011 25916 maintenance_manager.cc:643] P bfaa0960a398435dace372671a2cd854: FlushDeltaMemStoresOp(1a878e8b99674902be2730f412e72085) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4060,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:16.962558 25984 maintenance_manager.cc:419] P bfaa0960a398435dace372671a2cd854: Scheduling MajorDeltaCompactionOp(1a878e8b99674902be2730f412e72085): perf score=1.000000
I20260812 06:18:17.141155 25916 maintenance_manager.cc:643] P bfaa0960a398435dace372671a2cd854: MajorDeltaCompactionOp(1a878e8b99674902be2730f412e72085) complete. Timing: real 0.178s	user 0.115s	sys 0.060s 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":1890,"lbm_read_time_us":12750,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31368,"lbm_writes_lt_1ms":543,"mutex_wait_us":541,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:18:17.141862 25984 maintenance_manager.cc:419] P bfaa0960a398435dace372671a2cd854: Scheduling FlushDeltaMemStoresOp(1a878e8b99674902be2730f412e72085): perf score=14.095187
I20260812 06:18:17.204770 25916 maintenance_manager.cc:643] P bfaa0960a398435dace372671a2cd854: FlushDeltaMemStoresOp(1a878e8b99674902be2730f412e72085) complete. Timing: real 0.063s	user 0.033s	sys 0.022s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20422,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:17.205435 25984 maintenance_manager.cc:419] P bfaa0960a398435dace372671a2cd854: Scheduling FlushDeltaMemStoresOp(1a878e8b99674902be2730f412e72085): perf score=2.188937
I20260812 06:18:17.222069 25916 maintenance_manager.cc:643] P bfaa0960a398435dace372671a2cd854: FlushDeltaMemStoresOp(1a878e8b99674902be2730f412e72085) complete. Timing: real 0.016s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6562,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:17.222548 25984 maintenance_manager.cc:419] P bfaa0960a398435dace372671a2cd854: Scheduling MajorDeltaCompactionOp(1a878e8b99674902be2730f412e72085): perf score=1.000000
I20260812 06:18:17.404024 25916 maintenance_manager.cc:643] P bfaa0960a398435dace372671a2cd854: MajorDeltaCompactionOp(1a878e8b99674902be2730f412e72085) complete. Timing: real 0.181s	user 0.137s	sys 0.035s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1388,"lbm_read_time_us":12014,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28416,"lbm_writes_lt_1ms":543,"mutex_wait_us":318,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":17920,"update_count":2500}
I20260812 06:18:17.404877 25984 maintenance_manager.cc:419] P bfaa0960a398435dace372671a2cd854: Scheduling FlushDeltaMemStoresOp(1a878e8b99674902be2730f412e72085): perf score=14.095187
I20260812 06:18:17.467912 25916 maintenance_manager.cc:643] P bfaa0960a398435dace372671a2cd854: FlushDeltaMemStoresOp(1a878e8b99674902be2730f412e72085) complete. Timing: real 0.063s	user 0.035s	sys 0.027s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":24909,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:18:17.468521 25984 maintenance_manager.cc:419] P bfaa0960a398435dace372671a2cd854: Scheduling FlushDeltaMemStoresOp(1a878e8b99674902be2730f412e72085): perf score=2.188937
I20260812 06:18:17.480108 25916 maintenance_manager.cc:643] P bfaa0960a398435dace372671a2cd854: FlushDeltaMemStoresOp(1a878e8b99674902be2730f412e72085) complete. Timing: real 0.011s	user 0.003s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4447,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:17.480842 25984 maintenance_manager.cc:419] P bfaa0960a398435dace372671a2cd854: Scheduling MajorDeltaCompactionOp(1a878e8b99674902be2730f412e72085): perf score=1.000000
I20260812 06:18:17.656034 25916 maintenance_manager.cc:643] P bfaa0960a398435dace372671a2cd854: MajorDeltaCompactionOp(1a878e8b99674902be2730f412e72085) complete. Timing: real 0.175s	user 0.116s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774691,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":239,"lbm_read_time_us":13636,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26692,"lbm_writes_lt_1ms":543,"mutex_wait_us":25,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":37760,"update_count":2500}
I20260812 06:18:17.657008 25984 maintenance_manager.cc:419] P bfaa0960a398435dace372671a2cd854: Scheduling FlushDeltaMemStoresOp(1a878e8b99674902be2730f412e72085): perf score=11.118625
I20260812 06:18:17.689431 25916 maintenance_manager.cc:643] P bfaa0960a398435dace372671a2cd854: FlushDeltaMemStoresOp(1a878e8b99674902be2730f412e72085) complete. Timing: real 0.032s	user 0.010s	sys 0.020s Metrics: {"bytes_written":13292062,"delete_count":0,"lbm_write_time_us":14053,"lbm_writes_lt_1ms":327,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":1620}
I20260812 06:18:17.690013 25984 maintenance_manager.cc:419] P bfaa0960a398435dace372671a2cd854: Scheduling FlushDeltaMemStoresOp(1a878e8b99674902be2730f412e72085): perf score=1.196750
I20260812 06:18:17.713764 25916 maintenance_manager.cc:643] P bfaa0960a398435dace372671a2cd854: FlushDeltaMemStoresOp(1a878e8b99674902be2730f412e72085) complete. Timing: real 0.024s	user 0.000s	sys 0.011s Metrics: {"bytes_written":3118055,"delete_count":0,"lbm_write_time_us":4719,"lbm_writes_lt_1ms":79,"reinsert_count":0,"update_count":380}
I20260812 06:18:17.714478 25984 maintenance_manager.cc:419] P bfaa0960a398435dace372671a2cd854: Scheduling FlushDeltaMemStoresOp(1a878e8b99674902be2730f412e72085): perf score=2.188937
I20260812 06:18:17.736200 25916 maintenance_manager.cc:643] P bfaa0960a398435dace372671a2cd854: FlushDeltaMemStoresOp(1a878e8b99674902be2730f412e72085) complete. Timing: real 0.022s	user 0.007s	sys 0.014s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4391,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:17.736780 25984 maintenance_manager.cc:419] P bfaa0960a398435dace372671a2cd854: Scheduling FlushMRSOp(1a878e8b99674902be2730f412e72085): perf score=1.000000
I20260812 06:18:17.772023 25916 maintenance_manager.cc:643] P bfaa0960a398435dace372671a2cd854: FlushMRSOp(1a878e8b99674902be2730f412e72085) complete. Timing: real 0.035s	user 0.028s	sys 0.005s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":86,"dirs.run_cpu_time_us":263,"dirs.run_wall_time_us":1530,"drs_written":1,"lbm_read_time_us":111,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1598,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:18:17.772715 25984 maintenance_manager.cc:419] P bfaa0960a398435dace372671a2cd854: Scheduling LogGCOp(1a878e8b99674902be2730f412e72085): free 132571283 bytes of WAL
I20260812 06:18:17.772987 25916 log_reader.cc:385] T 1a878e8b99674902be2730f412e72085: removed 13 log segments from log reader
I20260812 06:18:17.773039 25916 log.cc:1079] T 1a878e8b99674902be2730f412e72085 P bfaa0960a398435dace372671a2cd854: Deleting log segment in path: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515488796982-25591-0/minicluster-data/ts-0-root/wals/1a878e8b99674902be2730f412e72085/wal-000000014 (ops 67-70)
I20260812 06:18:17.773068 25916 log.cc:1079] T 1a878e8b99674902be2730f412e72085 P bfaa0960a398435dace372671a2cd854: Deleting log segment in path: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515488796982-25591-0/minicluster-data/ts-0-root/wals/1a878e8b99674902be2730f412e72085/wal-000000015 (ops 71-75)
I20260812 06:18:17.773124 25916 log.cc:1079] T 1a878e8b99674902be2730f412e72085 P bfaa0960a398435dace372671a2cd854: Deleting log segment in path: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515488796982-25591-0/minicluster-data/ts-0-root/wals/1a878e8b99674902be2730f412e72085/wal-000000016 (ops 76-80)
I20260812 06:18:17.773169 25916 log.cc:1079] T 1a878e8b99674902be2730f412e72085 P bfaa0960a398435dace372671a2cd854: Deleting log segment in path: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515488796982-25591-0/minicluster-data/ts-0-root/wals/1a878e8b99674902be2730f412e72085/wal-000000017 (ops 81-85)
I20260812 06:18:17.773188 25916 log.cc:1079] T 1a878e8b99674902be2730f412e72085 P bfaa0960a398435dace372671a2cd854: Deleting log segment in path: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515488796982-25591-0/minicluster-data/ts-0-root/wals/1a878e8b99674902be2730f412e72085/wal-000000018 (ops 86-90)
I20260812 06:18:17.773239 25916 log.cc:1079] T 1a878e8b99674902be2730f412e72085 P bfaa0960a398435dace372671a2cd854: Deleting log segment in path: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515488796982-25591-0/minicluster-data/ts-0-root/wals/1a878e8b99674902be2730f412e72085/wal-000000019 (ops 91-95)
I20260812 06:18:17.773281 25916 log.cc:1079] T 1a878e8b99674902be2730f412e72085 P bfaa0960a398435dace372671a2cd854: Deleting log segment in path: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515488796982-25591-0/minicluster-data/ts-0-root/wals/1a878e8b99674902be2730f412e72085/wal-000000020 (ops 96-100)
I20260812 06:18:17.773347 25916 log.cc:1079] T 1a878e8b99674902be2730f412e72085 P bfaa0960a398435dace372671a2cd854: Deleting log segment in path: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515488796982-25591-0/minicluster-data/ts-0-root/wals/1a878e8b99674902be2730f412e72085/wal-000000021 (ops 101-105)
I20260812 06:18:17.773393 25916 log.cc:1079] T 1a878e8b99674902be2730f412e72085 P bfaa0960a398435dace372671a2cd854: Deleting log segment in path: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515488796982-25591-0/minicluster-data/ts-0-root/wals/1a878e8b99674902be2730f412e72085/wal-000000022 (ops 106-110)
I20260812 06:18:17.773432 25916 log.cc:1079] T 1a878e8b99674902be2730f412e72085 P bfaa0960a398435dace372671a2cd854: Deleting log segment in path: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515488796982-25591-0/minicluster-data/ts-0-root/wals/1a878e8b99674902be2730f412e72085/wal-000000023 (ops 111-114)
I20260812 06:18:17.773460 25916 log.cc:1079] T 1a878e8b99674902be2730f412e72085 P bfaa0960a398435dace372671a2cd854: Deleting log segment in path: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515488796982-25591-0/minicluster-data/ts-0-root/wals/1a878e8b99674902be2730f412e72085/wal-000000024 (ops 115-119)
I20260812 06:18:17.773494 25916 log.cc:1079] T 1a878e8b99674902be2730f412e72085 P bfaa0960a398435dace372671a2cd854: Deleting log segment in path: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515488796982-25591-0/minicluster-data/ts-0-root/wals/1a878e8b99674902be2730f412e72085/wal-000000025 (ops 120-124)
I20260812 06:18:17.773531 25916 log.cc:1079] T 1a878e8b99674902be2730f412e72085 P bfaa0960a398435dace372671a2cd854: Deleting log segment in path: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515488796982-25591-0/minicluster-data/ts-0-root/wals/1a878e8b99674902be2730f412e72085/wal-000000026 (ops 125-129)
I20260812 06:18:17.801324 25916 maintenance_manager.cc:643] P bfaa0960a398435dace372671a2cd854: LogGCOp(1a878e8b99674902be2730f412e72085) complete. Timing: real 0.028s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:18:17.801725 25984 maintenance_manager.cc:419] P bfaa0960a398435dace372671a2cd854: Scheduling UndoDeltaBlockGCOp(1a878e8b99674902be2730f412e72085): 483 bytes on disk
I20260812 06:18:17.802150 25916 maintenance_manager.cc:643] P bfaa0960a398435dace372671a2cd854: UndoDeltaBlockGCOp(1a878e8b99674902be2730f412e72085) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4}
I20260812 06:18:17.802685 25984 maintenance_manager.cc:419] P bfaa0960a398435dace372671a2cd854: Scheduling FlushDeltaMemStoresOp(1a878e8b99674902be2730f412e72085): perf score=3.181125
I20260812 06:18:17.825848 25916 maintenance_manager.cc:643] P bfaa0960a398435dace372671a2cd854: FlushDeltaMemStoresOp(1a878e8b99674902be2730f412e72085) complete. Timing: real 0.023s	user 0.008s	sys 0.008s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":6908,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:17.826363 25984 maintenance_manager.cc:419] P bfaa0960a398435dace372671a2cd854: Scheduling FlushDeltaMemStoresOp(1a878e8b99674902be2730f412e72085): perf score=2.188937
I20260812 06:18:17.836426 25916 maintenance_manager.cc:643] P bfaa0960a398435dace372671a2cd854: FlushDeltaMemStoresOp(1a878e8b99674902be2730f412e72085) complete. Timing: real 0.010s	user 0.004s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3721,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:17.836884 25984 maintenance_manager.cc:419] P bfaa0960a398435dace372671a2cd854: Scheduling MajorDeltaCompactionOp(1a878e8b99674902be2730f412e72085): perf score=1.000000
I20260812 06:18:18.072738 25916 maintenance_manager.cc:643] P bfaa0960a398435dace372671a2cd854: MajorDeltaCompactionOp(1a878e8b99674902be2730f412e72085) complete. Timing: real 0.236s	user 0.161s	sys 0.073s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32979827,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":643,"lbm_read_time_us":13910,"lbm_reads_lt_1ms":775,"lbm_write_time_us":42239,"lbm_writes_lt_1ms":743,"mutex_wait_us":62,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":13184,"thread_start_us":88,"threads_started":1,"update_count":3500}
I20260812 06:18:18.073897 25984 maintenance_manager.cc:419] P bfaa0960a398435dace372671a2cd854: Scheduling FlushDeltaMemStoresOp(1a878e8b99674902be2730f412e72085): perf score=16.079562
I20260812 06:18:18.135810 25916 maintenance_manager.cc:643] P bfaa0960a398435dace372671a2cd854: FlushDeltaMemStoresOp(1a878e8b99674902be2730f412e72085) complete. Timing: real 0.062s	user 0.042s	sys 0.013s Metrics: {"bytes_written":17927795,"delete_count":0,"lbm_write_time_us":26228,"lbm_writes_lt_1ms":440,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2185}
I20260812 06:18:18.136559 25984 maintenance_manager.cc:419] P bfaa0960a398435dace372671a2cd854: Scheduling FlushDeltaMemStoresOp(1a878e8b99674902be2730f412e72085): perf score=1.196750
I20260812 06:18:18.152500 25916 maintenance_manager.cc:643] P bfaa0960a398435dace372671a2cd854: FlushDeltaMemStoresOp(1a878e8b99674902be2730f412e72085) complete. Timing: real 0.016s	user 0.006s	sys 0.002s Metrics: {"bytes_written":2994984,"delete_count":0,"lbm_write_time_us":3001,"lbm_writes_lt_1ms":76,"reinsert_count":0,"update_count":365}
I20260812 06:18:18.152992 25984 maintenance_manager.cc:419] P bfaa0960a398435dace372671a2cd854: Scheduling FlushDeltaMemStoresOp(1a878e8b99674902be2730f412e72085): perf score=2.188937
I20260812 06:18:18.163010 25916 maintenance_manager.cc:643] P bfaa0960a398435dace372671a2cd854: FlushDeltaMemStoresOp(1a878e8b99674902be2730f412e72085) complete. Timing: real 0.010s	user 0.007s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3797,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:18.163514 25984 maintenance_manager.cc:419] P bfaa0960a398435dace372671a2cd854: Scheduling MajorDeltaCompactionOp(1a878e8b99674902be2730f412e72085): perf score=1.000000
I20260812 06:18:18.401872 25916 maintenance_manager.cc:643] P bfaa0960a398435dace372671a2cd854: MajorDeltaCompactionOp(1a878e8b99674902be2730f412e72085) complete. Timing: real 0.238s	user 0.130s	sys 0.095s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877184,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":709,"lbm_read_time_us":15090,"lbm_reads_lt_1ms":673,"lbm_write_time_us":36319,"lbm_writes_lt_1ms":643,"mutex_wait_us":285,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":11904,"update_count":3000}
I20260812 06:18:18.402712 25984 maintenance_manager.cc:419] P bfaa0960a398435dace372671a2cd854: Scheduling FlushDeltaMemStoresOp(1a878e8b99674902be2730f412e72085): perf score=18.063937
I20260812 06:18:18.477564 25916 maintenance_manager.cc:643] P bfaa0960a398435dace372671a2cd854: FlushDeltaMemStoresOp(1a878e8b99674902be2730f412e72085) complete. Timing: real 0.075s	user 0.027s	sys 0.040s Metrics: {"bytes_written":20512333,"delete_count":0,"lbm_write_time_us":30671,"lbm_writes_lt_1ms":503,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":2500}
I20260812 06:18:18.478096 25984 maintenance_manager.cc:419] P bfaa0960a398435dace372671a2cd854: Scheduling FlushDeltaMemStoresOp(1a878e8b99674902be2730f412e72085): perf score=2.188937
I20260812 06:18:18.489843 25916 maintenance_manager.cc:643] P bfaa0960a398435dace372671a2cd854: FlushDeltaMemStoresOp(1a878e8b99674902be2730f412e72085) complete. Timing: real 0.012s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4195,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:18.490335 25984 maintenance_manager.cc:419] P bfaa0960a398435dace372671a2cd854: Scheduling MajorDeltaCompactionOp(1a878e8b99674902be2730f412e72085): perf score=1.000000
I20260812 06:18:18.705333 25916 maintenance_manager.cc:643] P bfaa0960a398435dace372671a2cd854: MajorDeltaCompactionOp(1a878e8b99674902be2730f412e72085) complete. Timing: real 0.215s	user 0.135s	sys 0.079s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877120,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":693,"lbm_read_time_us":15089,"lbm_reads_lt_1ms":672,"lbm_write_time_us":35407,"lbm_writes_lt_1ms":643,"mutex_wait_us":298,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":17920,"update_count":3000}
I20260812 06:18:18.706122 25984 maintenance_manager.cc:419] P bfaa0960a398435dace372671a2cd854: Scheduling FlushDeltaMemStoresOp(1a878e8b99674902be2730f412e72085): perf score=15.087375
I20260812 06:18:18.753825 25916 maintenance_manager.cc:643] P bfaa0960a398435dace372671a2cd854: FlushDeltaMemStoresOp(1a878e8b99674902be2730f412e72085) complete. Timing: real 0.048s	user 0.034s	sys 0.012s Metrics: {"bytes_written":16820143,"delete_count":0,"lbm_write_time_us":20745,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:18:18.754336 25984 maintenance_manager.cc:419] P bfaa0960a398435dace372671a2cd854: Scheduling FlushDeltaMemStoresOp(1a878e8b99674902be2730f412e72085): perf score=2.188937
I20260812 06:18:18.781606 25916 maintenance_manager.cc:643] P bfaa0960a398435dace372671a2cd854: FlushDeltaMemStoresOp(1a878e8b99674902be2730f412e72085) complete. Timing: real 0.027s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5339,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:18.782105 25984 maintenance_manager.cc:419] P bfaa0960a398435dace372671a2cd854: Scheduling FlushDeltaMemStoresOp(1a878e8b99674902be2730f412e72085): perf score=2.188937
I20260812 06:18:18.793119 25916 maintenance_manager.cc:643] P bfaa0960a398435dace372671a2cd854: FlushDeltaMemStoresOp(1a878e8b99674902be2730f412e72085) complete. Timing: real 0.011s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4242,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:18.793720 25984 maintenance_manager.cc:419] P bfaa0960a398435dace372671a2cd854: Scheduling MajorDeltaCompactionOp(1a878e8b99674902be2730f412e72085): perf score=1.000000
I20260812 06:18:19.006371 25916 maintenance_manager.cc:643] P bfaa0960a398435dace372671a2cd854: MajorDeltaCompactionOp(1a878e8b99674902be2730f412e72085) complete. Timing: real 0.212s	user 0.164s	sys 0.032s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877207,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1752,"lbm_read_time_us":14565,"lbm_reads_lt_1ms":673,"lbm_write_time_us":33884,"lbm_writes_lt_1ms":643,"mutex_wait_us":609,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":4736,"update_count":3000}
I20260812 06:18:19.006979 25984 maintenance_manager.cc:419] P bfaa0960a398435dace372671a2cd854: Scheduling FlushDeltaMemStoresOp(1a878e8b99674902be2730f412e72085): perf score=18.063937
I20260812 06:18:19.070487 25916 maintenance_manager.cc:643] P bfaa0960a398435dace372671a2cd854: FlushDeltaMemStoresOp(1a878e8b99674902be2730f412e72085) complete. Timing: real 0.063s	user 0.057s	sys 0.004s Metrics: {"bytes_written":20512319,"delete_count":0,"lbm_write_time_us":29250,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:19.071502 25984 maintenance_manager.cc:419] P bfaa0960a398435dace372671a2cd854: Scheduling FlushDeltaMemStoresOp(1a878e8b99674902be2730f412e72085): perf score=2.188937
I20260812 06:18:19.089615 25916 maintenance_manager.cc:643] P bfaa0960a398435dace372671a2cd854: FlushDeltaMemStoresOp(1a878e8b99674902be2730f412e72085) complete. Timing: real 0.018s	user 0.016s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6360,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:19.090391 25984 maintenance_manager.cc:419] P bfaa0960a398435dace372671a2cd854: Scheduling MajorDeltaCompactionOp(1a878e8b99674902be2730f412e72085): perf score=1.000000
I20260812 06:18:19.301216 25916 maintenance_manager.cc:643] P bfaa0960a398435dace372671a2cd854: MajorDeltaCompactionOp(1a878e8b99674902be2730f412e72085) complete. Timing: real 0.211s	user 0.139s	sys 0.059s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877106,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":216,"lbm_read_time_us":13748,"lbm_reads_lt_1ms":664,"lbm_write_time_us":37173,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":7808,"update_count":3000}
I20260812 06:18:19.301888 25984 maintenance_manager.cc:419] P bfaa0960a398435dace372671a2cd854: Scheduling FlushDeltaMemStoresOp(1a878e8b99674902be2730f412e72085): perf score=18.063937
I20260812 06:18:19.371616 25916 maintenance_manager.cc:643] P bfaa0960a398435dace372671a2cd854: FlushDeltaMemStoresOp(1a878e8b99674902be2730f412e72085) complete. Timing: real 0.069s	user 0.044s	sys 0.019s Metrics: {"bytes_written":20512319,"delete_count":0,"lbm_write_time_us":30482,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:19.372208 25984 maintenance_manager.cc:419] P bfaa0960a398435dace372671a2cd854: Scheduling FlushDeltaMemStoresOp(1a878e8b99674902be2730f412e72085): perf score=2.188937
I20260812 06:18:19.384233 25916 maintenance_manager.cc:643] P bfaa0960a398435dace372671a2cd854: FlushDeltaMemStoresOp(1a878e8b99674902be2730f412e72085) complete. Timing: real 0.012s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4259,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:19.384783 25984 maintenance_manager.cc:419] P bfaa0960a398435dace372671a2cd854: Scheduling FlushMRSOp(1a878e8b99674902be2730f412e72085): perf score=1.000000
I20260812 06:18:19.413913 25916 maintenance_manager.cc:643] P bfaa0960a398435dace372671a2cd854: FlushMRSOp(1a878e8b99674902be2730f412e72085) complete. Timing: real 0.029s	user 0.023s	sys 0.004s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":66,"dirs.run_cpu_time_us":254,"dirs.run_wall_time_us":1441,"drs_written":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1957,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:18:19.414760 25984 maintenance_manager.cc:419] P bfaa0960a398435dace372671a2cd854: Scheduling LogGCOp(1a878e8b99674902be2730f412e72085): free 132571649 bytes of WAL
I20260812 06:18:19.415066 25916 log_reader.cc:385] T 1a878e8b99674902be2730f412e72085: removed 13 log segments from log reader
I20260812 06:18:19.415133 25916 log.cc:1079] T 1a878e8b99674902be2730f412e72085 P bfaa0960a398435dace372671a2cd854: Deleting log segment in path: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515488796982-25591-0/minicluster-data/ts-0-root/wals/1a878e8b99674902be2730f412e72085/wal-000000027 (ops 130-134)
I20260812 06:18:19.415174 25916 log.cc:1079] T 1a878e8b99674902be2730f412e72085 P bfaa0960a398435dace372671a2cd854: Deleting log segment in path: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515488796982-25591-0/minicluster-data/ts-0-root/wals/1a878e8b99674902be2730f412e72085/wal-000000028 (ops 135-139)
I20260812 06:18:19.415197 25916 log.cc:1079] T 1a878e8b99674902be2730f412e72085 P bfaa0960a398435dace372671a2cd854: Deleting log segment in path: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515488796982-25591-0/minicluster-data/ts-0-root/wals/1a878e8b99674902be2730f412e72085/wal-000000029 (ops 140-144)
I20260812 06:18:19.415227 25916 log.cc:1079] T 1a878e8b99674902be2730f412e72085 P bfaa0960a398435dace372671a2cd854: Deleting log segment in path: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515488796982-25591-0/minicluster-data/ts-0-root/wals/1a878e8b99674902be2730f412e72085/wal-000000030 (ops 145-149)
I20260812 06:18:19.415258 25916 log.cc:1079] T 1a878e8b99674902be2730f412e72085 P bfaa0960a398435dace372671a2cd854: Deleting log segment in path: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515488796982-25591-0/minicluster-data/ts-0-root/wals/1a878e8b99674902be2730f412e72085/wal-000000031 (ops 150-154)
I20260812 06:18:19.415292 25916 log.cc:1079] T 1a878e8b99674902be2730f412e72085 P bfaa0960a398435dace372671a2cd854: Deleting log segment in path: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515488796982-25591-0/minicluster-data/ts-0-root/wals/1a878e8b99674902be2730f412e72085/wal-000000032 (ops 155-158)
I20260812 06:18:19.415323 25916 log.cc:1079] T 1a878e8b99674902be2730f412e72085 P bfaa0960a398435dace372671a2cd854: Deleting log segment in path: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515488796982-25591-0/minicluster-data/ts-0-root/wals/1a878e8b99674902be2730f412e72085/wal-000000033 (ops 159-163)
I20260812 06:18:19.415349 25916 log.cc:1079] T 1a878e8b99674902be2730f412e72085 P bfaa0960a398435dace372671a2cd854: Deleting log segment in path: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515488796982-25591-0/minicluster-data/ts-0-root/wals/1a878e8b99674902be2730f412e72085/wal-000000034 (ops 164-168)
I20260812 06:18:19.415377 25916 log.cc:1079] T 1a878e8b99674902be2730f412e72085 P bfaa0960a398435dace372671a2cd854: Deleting log segment in path: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515488796982-25591-0/minicluster-data/ts-0-root/wals/1a878e8b99674902be2730f412e72085/wal-000000035 (ops 169-173)
I20260812 06:18:19.415402 25916 log.cc:1079] T 1a878e8b99674902be2730f412e72085 P bfaa0960a398435dace372671a2cd854: Deleting log segment in path: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515488796982-25591-0/minicluster-data/ts-0-root/wals/1a878e8b99674902be2730f412e72085/wal-000000036 (ops 174-178)
I20260812 06:18:19.415437 25916 log.cc:1079] T 1a878e8b99674902be2730f412e72085 P bfaa0960a398435dace372671a2cd854: Deleting log segment in path: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515488796982-25591-0/minicluster-data/ts-0-root/wals/1a878e8b99674902be2730f412e72085/wal-000000037 (ops 179-182)
I20260812 06:18:19.415481 25916 log.cc:1079] T 1a878e8b99674902be2730f412e72085 P bfaa0960a398435dace372671a2cd854: Deleting log segment in path: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515488796982-25591-0/minicluster-data/ts-0-root/wals/1a878e8b99674902be2730f412e72085/wal-000000038 (ops 183-187)
I20260812 06:18:19.415505 25916 log.cc:1079] T 1a878e8b99674902be2730f412e72085 P bfaa0960a398435dace372671a2cd854: Deleting log segment in path: /tmp/dist-test-taskNXRHuq/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515488796982-25591-0/minicluster-data/ts-0-root/wals/1a878e8b99674902be2730f412e72085/wal-000000039 (ops 188-192)
I20260812 06:18:19.445338 25916 maintenance_manager.cc:643] P bfaa0960a398435dace372671a2cd854: LogGCOp(1a878e8b99674902be2730f412e72085) complete. Timing: real 0.030s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:18:19.445804 25984 maintenance_manager.cc:419] P bfaa0960a398435dace372671a2cd854: Scheduling FlushDeltaMemStoresOp(1a878e8b99674902be2730f412e72085): perf score=2.188937
I20260812 06:18:19.470252 25916 maintenance_manager.cc:643] P bfaa0960a398435dace372671a2cd854: FlushDeltaMemStoresOp(1a878e8b99674902be2730f412e72085) complete. Timing: real 0.024s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6481,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:19.470723 25984 maintenance_manager.cc:419] P bfaa0960a398435dace372671a2cd854: Scheduling UndoDeltaBlockGCOp(1a878e8b99674902be2730f412e72085): 492 bytes on disk
I20260812 06:18:19.471145 25916 maintenance_manager.cc:643] P bfaa0960a398435dace372671a2cd854: UndoDeltaBlockGCOp(1a878e8b99674902be2730f412e72085) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4}
I20260812 06:18:19.471676 25984 maintenance_manager.cc:419] P bfaa0960a398435dace372671a2cd854: Scheduling FlushDeltaMemStoresOp(1a878e8b99674902be2730f412e72085): perf score=2.188937
I20260812 06:18:19.482491 25916 maintenance_manager.cc:643] P bfaa0960a398435dace372671a2cd854: FlushDeltaMemStoresOp(1a878e8b99674902be2730f412e72085) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4166,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:19.483559 25984 maintenance_manager.cc:419] P bfaa0960a398435dace372671a2cd854: Scheduling MajorDeltaCompactionOp(1a878e8b99674902be2730f412e72085): perf score=1.000000
I20260812 06:18:19.613935 25591 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.006s	user 1.851s	sys 0.163s
I20260812 06:18:19.685871 25916 maintenance_manager.cc:643] P bfaa0960a398435dace372671a2cd854: MajorDeltaCompactionOp(1a878e8b99674902be2730f412e72085) complete. Timing: real 0.202s	user 0.148s	sys 0.052s Metrics: {"cfile_cache_miss":834,"cfile_cache_miss_bytes":37082168,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"lbm_read_time_us":14045,"lbm_reads_lt_1ms":870,"lbm_write_time_us":44136,"lbm_writes_lt_1ms":843,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":4000}
I20260812 06:18:19.686405 25984 maintenance_manager.cc:419] P bfaa0960a398435dace372671a2cd854: Scheduling FlushDeltaMemStoresOp(1a878e8b99674902be2730f412e72085): perf score=10.126437
I20260812 06:18:19.708837 25591 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.094s	user 0.002s	sys 0.000s
I20260812 06:18:19.709396 25591 tablet_server.cc:179] TabletServer@127.24.253.193:0 shutting down...
I20260812 06:18:19.721721 25916 maintenance_manager.cc:643] P bfaa0960a398435dace372671a2cd854: FlushDeltaMemStoresOp(1a878e8b99674902be2730f412e72085) complete. Timing: real 0.035s	user 0.015s	sys 0.018s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15637,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:18:19.722292 25591 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:19.722704 25591 tablet_replica.cc:333] T 1a878e8b99674902be2730f412e72085 P bfaa0960a398435dace372671a2cd854: stopping tablet replica
I20260812 06:18:19.722877 25591 raft_consensus.cc:2243] T 1a878e8b99674902be2730f412e72085 P bfaa0960a398435dace372671a2cd854 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:19.723073 25591 raft_consensus.cc:2272] T 1a878e8b99674902be2730f412e72085 P bfaa0960a398435dace372671a2cd854 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:19.736909 25591 tablet_server.cc:196] TabletServer@127.24.253.193:0 shutdown complete.
I20260812 06:18:19.763625 25591 master.cc:562] Master@127.24.253.254:39663 shutting down...
I20260812 06:18:19.767225 25591 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 59c96fd322bc48118db776e1f3fc2384 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:19.767391 25591 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 59c96fd322bc48118db776e1f3fc2384 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:19.767441 25591 tablet_replica.cc:333] T 00000000000000000000000000000000 P 59c96fd322bc48118db776e1f3fc2384: stopping tablet replica
I20260812 06:18:19.780164 25591 master.cc:584] Master@127.24.253.254:39663 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5457 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11058 ms total)

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