[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:19:15.942238 20911 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.20.107.254:45769
I20260812 06:19:15.943279 20911 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:19:15.943863 20911 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:15.949959 20918 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:15.950026 20911 server_base.cc:1061] running on GCE node
W20260812 06:19:15.949966 20920 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:15.950253 20917 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:15.950790 20911 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:15.950901 20911 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:15.950961 20911 hybrid_clock.cc:648] HybridClock initialized: now 1786515555950958 us; error 0 us; skew 500 ppm
I20260812 06:19:15.955677 20911 webserver.cc:533] Webserver started at http://127.20.107.254:40699/ using document root <none> and password file <none>
I20260812 06:19:15.956257 20911 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:15.956319 20911 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:15.956595 20911 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:15.958261 20911 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515555931601-20911-0/minicluster-data/master-0-root/instance:
uuid: "32ef45e6cc80484f8d917f64d4f60789"
format_stamp: "Formatted at 2026-08-12 06:19:15 on dist-test-slave-vkjp"
I20260812 06:19:15.961675 20911 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.005s	sys 0.000s
I20260812 06:19:15.963753 20928 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:15.964730 20911 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:15.964860 20911 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515555931601-20911-0/minicluster-data/master-0-root
uuid: "32ef45e6cc80484f8d917f64d4f60789"
format_stamp: "Formatted at 2026-08-12 06:19:15 on dist-test-slave-vkjp"
I20260812 06:19:15.964969 20911 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515555931601-20911-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515555931601-20911-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515555931601-20911-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:15.976061 20911 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:15.976652 20911 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:19:15.976827 20911 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:15.984607 20911 rpc_server.cc:307] RPC server started. Bound to: 127.20.107.254:45769
I20260812 06:19:15.984611 20990 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.20.107.254:45769 every 8 connection(s)
I20260812 06:19:15.986725 20991 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:15.991950 20991 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 32ef45e6cc80484f8d917f64d4f60789: Bootstrap starting.
I20260812 06:19:15.994135 20991 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 32ef45e6cc80484f8d917f64d4f60789: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:15.994999 20991 log.cc:826] T 00000000000000000000000000000000 P 32ef45e6cc80484f8d917f64d4f60789: Log is configured to *not* fsync() on all Append() calls
I20260812 06:19:15.996536 20991 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 32ef45e6cc80484f8d917f64d4f60789: No bootstrap required, opened a new log
I20260812 06:19:15.999099 20991 raft_consensus.cc:359] T 00000000000000000000000000000000 P 32ef45e6cc80484f8d917f64d4f60789 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "32ef45e6cc80484f8d917f64d4f60789" member_type: VOTER }
I20260812 06:19:15.999245 20991 raft_consensus.cc:385] T 00000000000000000000000000000000 P 32ef45e6cc80484f8d917f64d4f60789 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:15.999285 20991 raft_consensus.cc:740] T 00000000000000000000000000000000 P 32ef45e6cc80484f8d917f64d4f60789 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 32ef45e6cc80484f8d917f64d4f60789, State: Initialized, Role: FOLLOWER
I20260812 06:19:15.999765 20991 consensus_queue.cc:260] T 00000000000000000000000000000000 P 32ef45e6cc80484f8d917f64d4f60789 [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: "32ef45e6cc80484f8d917f64d4f60789" member_type: VOTER }
I20260812 06:19:15.999888 20991 raft_consensus.cc:399] T 00000000000000000000000000000000 P 32ef45e6cc80484f8d917f64d4f60789 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:15.999941 20991 raft_consensus.cc:493] T 00000000000000000000000000000000 P 32ef45e6cc80484f8d917f64d4f60789 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:16.000023 20991 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 32ef45e6cc80484f8d917f64d4f60789 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:16.000696 20991 raft_consensus.cc:515] T 00000000000000000000000000000000 P 32ef45e6cc80484f8d917f64d4f60789 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "32ef45e6cc80484f8d917f64d4f60789" member_type: VOTER }
I20260812 06:19:16.001065 20991 leader_election.cc:304] T 00000000000000000000000000000000 P 32ef45e6cc80484f8d917f64d4f60789 [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: 32ef45e6cc80484f8d917f64d4f60789; no voters: 
I20260812 06:19:16.001313 20991 leader_election.cc:290] T 00000000000000000000000000000000 P 32ef45e6cc80484f8d917f64d4f60789 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:16.001466 20994 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 32ef45e6cc80484f8d917f64d4f60789 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:16.001703 20994 raft_consensus.cc:697] T 00000000000000000000000000000000 P 32ef45e6cc80484f8d917f64d4f60789 [term 1 LEADER]: Becoming Leader. State: Replica: 32ef45e6cc80484f8d917f64d4f60789, State: Running, Role: LEADER
I20260812 06:19:16.002094 20994 consensus_queue.cc:237] T 00000000000000000000000000000000 P 32ef45e6cc80484f8d917f64d4f60789 [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: "32ef45e6cc80484f8d917f64d4f60789" member_type: VOTER }
I20260812 06:19:16.002321 20991 sys_catalog.cc:565] T 00000000000000000000000000000000 P 32ef45e6cc80484f8d917f64d4f60789 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:16.004056 20996 sys_catalog.cc:455] T 00000000000000000000000000000000 P 32ef45e6cc80484f8d917f64d4f60789 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 32ef45e6cc80484f8d917f64d4f60789. Latest consensus state: current_term: 1 leader_uuid: "32ef45e6cc80484f8d917f64d4f60789" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "32ef45e6cc80484f8d917f64d4f60789" member_type: VOTER } }
I20260812 06:19:16.004096 20995 sys_catalog.cc:455] T 00000000000000000000000000000000 P 32ef45e6cc80484f8d917f64d4f60789 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "32ef45e6cc80484f8d917f64d4f60789" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "32ef45e6cc80484f8d917f64d4f60789" member_type: VOTER } }
I20260812 06:19:16.004187 20996 sys_catalog.cc:458] T 00000000000000000000000000000000 P 32ef45e6cc80484f8d917f64d4f60789 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:16.004187 20995 sys_catalog.cc:458] T 00000000000000000000000000000000 P 32ef45e6cc80484f8d917f64d4f60789 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:16.004637 21006 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:16.004739 20911 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:16.006800 21006 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:16.010828 21006 catalog_manager.cc:1383] Generated new cluster ID: b217b38990b243ed9565e5eaba4bbb5f
I20260812 06:19:16.010905 21006 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:16.025453 21006 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:16.026249 21006 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:16.040972 21006 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 32ef45e6cc80484f8d917f64d4f60789: Generated new TSK 0
I20260812 06:19:16.041601 21006 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:16.069995 20911 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:16.073000 21017 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:16.073047 21019 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:16.073166 21016 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:16.073323 20911 server_base.cc:1061] running on GCE node
I20260812 06:19:16.073626 20911 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:16.073671 20911 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:16.073688 20911 hybrid_clock.cc:648] HybridClock initialized: now 1786515556073688 us; error 0 us; skew 500 ppm
I20260812 06:19:16.074635 20911 webserver.cc:533] Webserver started at http://127.20.107.193:33735/ using document root <none> and password file <none>
I20260812 06:19:16.074810 20911 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:16.074867 20911 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:16.074978 20911 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:16.075412 20911 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515555931601-20911-0/minicluster-data/ts-0-root/instance:
uuid: "6c90b85b007d4b3d87430ccd414f88ae"
format_stamp: "Formatted at 2026-08-12 06:19:16 on dist-test-slave-vkjp"
I20260812 06:19:16.076937 20911 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:16.077900 21027 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:16.078142 20911 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:16.078213 20911 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515555931601-20911-0/minicluster-data/ts-0-root
uuid: "6c90b85b007d4b3d87430ccd414f88ae"
format_stamp: "Formatted at 2026-08-12 06:19:16 on dist-test-slave-vkjp"
I20260812 06:19:16.078296 20911 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515555931601-20911-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515555931601-20911-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515555931601-20911-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:16.091681 20911 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:16.092159 20911 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:16.092682 20911 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:16.093564 20911 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:16.093614 20911 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:16.093683 20911 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:16.093729 20911 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:16.100446 20911 rpc_server.cc:307] RPC server started. Bound to: 127.20.107.193:38863
I20260812 06:19:16.100517 21108 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.20.107.193:38863 every 8 connection(s)
I20260812 06:19:16.115644 21109 heartbeater.cc:344] Connected to a master server at 127.20.107.254:45769
I20260812 06:19:16.115931 21109 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:16.116372 21109 heartbeater.cc:507] Master 127.20.107.254:45769 requested a full tablet report, sending...
I20260812 06:19:16.119295 20948 ts_manager.cc:194] Registered new tserver with Master: 6c90b85b007d4b3d87430ccd414f88ae (127.20.107.193:38863)
I20260812 06:19:16.119374 20911 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.018262075s
I20260812 06:19:16.120784 20948 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:52958
I20260812 06:19:16.130257 20948 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:52968:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:19:16.148277 21062 tablet_service.cc:1511] Processing CreateTablet for tablet 956c15bce98c48fcb032d12f9e74e345 (DEFAULT_TABLE table=heavy-update-compaction-test [id=a1718e51af544785a3d5bd02afc1d33b]), partition=
I20260812 06:19:16.148764 21062 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 956c15bce98c48fcb032d12f9e74e345. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:16.151178 21126 tablet_bootstrap.cc:492] T 956c15bce98c48fcb032d12f9e74e345 P 6c90b85b007d4b3d87430ccd414f88ae: Bootstrap starting.
I20260812 06:19:16.152261 21126 tablet_bootstrap.cc:654] T 956c15bce98c48fcb032d12f9e74e345 P 6c90b85b007d4b3d87430ccd414f88ae: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:16.153664 21126 tablet_bootstrap.cc:492] T 956c15bce98c48fcb032d12f9e74e345 P 6c90b85b007d4b3d87430ccd414f88ae: No bootstrap required, opened a new log
I20260812 06:19:16.153779 21126 ts_tablet_manager.cc:1403] T 956c15bce98c48fcb032d12f9e74e345 P 6c90b85b007d4b3d87430ccd414f88ae: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:19:16.154579 21126 raft_consensus.cc:359] T 956c15bce98c48fcb032d12f9e74e345 P 6c90b85b007d4b3d87430ccd414f88ae [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6c90b85b007d4b3d87430ccd414f88ae" member_type: VOTER last_known_addr { host: "127.20.107.193" port: 38863 } }
I20260812 06:19:16.154708 21126 raft_consensus.cc:385] T 956c15bce98c48fcb032d12f9e74e345 P 6c90b85b007d4b3d87430ccd414f88ae [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:16.154752 21126 raft_consensus.cc:740] T 956c15bce98c48fcb032d12f9e74e345 P 6c90b85b007d4b3d87430ccd414f88ae [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 6c90b85b007d4b3d87430ccd414f88ae, State: Initialized, Role: FOLLOWER
I20260812 06:19:16.154939 21126 consensus_queue.cc:260] T 956c15bce98c48fcb032d12f9e74e345 P 6c90b85b007d4b3d87430ccd414f88ae [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: "6c90b85b007d4b3d87430ccd414f88ae" member_type: VOTER last_known_addr { host: "127.20.107.193" port: 38863 } }
I20260812 06:19:16.155138 21126 raft_consensus.cc:399] T 956c15bce98c48fcb032d12f9e74e345 P 6c90b85b007d4b3d87430ccd414f88ae [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:16.155239 21126 raft_consensus.cc:493] T 956c15bce98c48fcb032d12f9e74e345 P 6c90b85b007d4b3d87430ccd414f88ae [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:16.155344 21126 raft_consensus.cc:3060] T 956c15bce98c48fcb032d12f9e74e345 P 6c90b85b007d4b3d87430ccd414f88ae [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:16.156373 21126 raft_consensus.cc:515] T 956c15bce98c48fcb032d12f9e74e345 P 6c90b85b007d4b3d87430ccd414f88ae [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6c90b85b007d4b3d87430ccd414f88ae" member_type: VOTER last_known_addr { host: "127.20.107.193" port: 38863 } }
I20260812 06:19:16.156576 21126 leader_election.cc:304] T 956c15bce98c48fcb032d12f9e74e345 P 6c90b85b007d4b3d87430ccd414f88ae [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: 6c90b85b007d4b3d87430ccd414f88ae; no voters: 
I20260812 06:19:16.156853 21126 leader_election.cc:290] T 956c15bce98c48fcb032d12f9e74e345 P 6c90b85b007d4b3d87430ccd414f88ae [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:16.156996 21129 raft_consensus.cc:2804] T 956c15bce98c48fcb032d12f9e74e345 P 6c90b85b007d4b3d87430ccd414f88ae [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:16.157245 21126 ts_tablet_manager.cc:1434] T 956c15bce98c48fcb032d12f9e74e345 P 6c90b85b007d4b3d87430ccd414f88ae: Time spent starting tablet: real 0.003s	user 0.004s	sys 0.000s
I20260812 06:19:16.157274 21129 raft_consensus.cc:697] T 956c15bce98c48fcb032d12f9e74e345 P 6c90b85b007d4b3d87430ccd414f88ae [term 1 LEADER]: Becoming Leader. State: Replica: 6c90b85b007d4b3d87430ccd414f88ae, State: Running, Role: LEADER
I20260812 06:19:16.157541 21129 consensus_queue.cc:237] T 956c15bce98c48fcb032d12f9e74e345 P 6c90b85b007d4b3d87430ccd414f88ae [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: "6c90b85b007d4b3d87430ccd414f88ae" member_type: VOTER last_known_addr { host: "127.20.107.193" port: 38863 } }
I20260812 06:19:16.157677 21109 heartbeater.cc:499] Master 127.20.107.254:45769 was elected leader, sending a full tablet report...
I20260812 06:19:16.161176 20947 catalog_manager.cc:5719] T 956c15bce98c48fcb032d12f9e74e345 P 6c90b85b007d4b3d87430ccd414f88ae reported cstate change: term changed from 0 to 1, leader changed from <none> to 6c90b85b007d4b3d87430ccd414f88ae (127.20.107.193). New cstate: current_term: 1 leader_uuid: "6c90b85b007d4b3d87430ccd414f88ae" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6c90b85b007d4b3d87430ccd414f88ae" member_type: VOTER last_known_addr { host: "127.20.107.193" port: 38863 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:16.230499 20911 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.056s	user 0.013s	sys 0.013s
I20260812 06:19:16.351522 21110 maintenance_manager.cc:419] P 6c90b85b007d4b3d87430ccd414f88ae: Scheduling FlushMRSOp(956c15bce98c48fcb032d12f9e74e345): perf score=15.086190
I20260812 06:19:16.504514 21033 maintenance_manager.cc:643] P 6c90b85b007d4b3d87430ccd414f88ae: FlushMRSOp(956c15bce98c48fcb032d12f9e74e345) complete. Timing: real 0.153s	user 0.129s	sys 0.021s Metrics: {"bytes_written":12307493,"cfile_init":1,"compiler_manager_pool.queue_time_us":251,"delete_count":0,"dirs.queue_time_us":73,"dirs.run_cpu_time_us":175,"dirs.run_wall_time_us":907,"drs_written":1,"lbm_read_time_us":51,"lbm_reads_lt_1ms":4,"lbm_write_time_us":38300,"lbm_writes_lt_1ms":657,"peak_mem_usage":0,"reinsert_count":0,"rows_written":103,"thread_start_us":157,"threads_started":1,"update_count":1500}
I20260812 06:19:16.505708 21110 maintenance_manager.cc:419] P 6c90b85b007d4b3d87430ccd414f88ae: Scheduling LogGCOp(956c15bce98c48fcb032d12f9e74e345): free 11976772 bytes of WAL
I20260812 06:19:16.506050 21033 log_reader.cc:385] T 956c15bce98c48fcb032d12f9e74e345: removed 1 log segments from log reader
I20260812 06:19:16.506127 21033 log.cc:1079] T 956c15bce98c48fcb032d12f9e74e345 P 6c90b85b007d4b3d87430ccd414f88ae: Deleting log segment in path: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515555931601-20911-0/minicluster-data/ts-0-root/wals/956c15bce98c48fcb032d12f9e74e345/wal-000000001 (ops 1-6)
I20260812 06:19:16.509336 21033 maintenance_manager.cc:643] P 6c90b85b007d4b3d87430ccd414f88ae: LogGCOp(956c15bce98c48fcb032d12f9e74e345) complete. Timing: real 0.003s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:19:16.509799 21110 maintenance_manager.cc:419] P 6c90b85b007d4b3d87430ccd414f88ae: Scheduling UndoDeltaBlockGCOp(956c15bce98c48fcb032d12f9e74e345): 12308959 bytes on disk
I20260812 06:19:16.510553 21033 maintenance_manager.cc:643] P 6c90b85b007d4b3d87430ccd414f88ae: UndoDeltaBlockGCOp(956c15bce98c48fcb032d12f9e74e345) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":86,"lbm_reads_lt_1ms":4}
I20260812 06:19:16.511152 21110 maintenance_manager.cc:419] P 6c90b85b007d4b3d87430ccd414f88ae: Scheduling FlushDeltaMemStoresOp(956c15bce98c48fcb032d12f9e74e345): perf score=2.188937
I20260812 06:19:16.528251 21033 maintenance_manager.cc:643] P 6c90b85b007d4b3d87430ccd414f88ae: FlushDeltaMemStoresOp(956c15bce98c48fcb032d12f9e74e345) complete. Timing: real 0.017s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6264,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:16.528707 21110 maintenance_manager.cc:419] P 6c90b85b007d4b3d87430ccd414f88ae: Scheduling MajorDeltaCompactionOp(956c15bce98c48fcb032d12f9e74e345): perf score=1.000000
I20260812 06:19:16.667734 21033 maintenance_manager.cc:643] P 6c90b85b007d4b3d87430ccd414f88ae: MajorDeltaCompactionOp(956c15bce98c48fcb032d12f9e74e345) complete. Timing: real 0.139s	user 0.107s	sys 0.031s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631315,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":990,"lbm_read_time_us":8317,"lbm_reads_lt_1ms":460,"lbm_write_time_us":26251,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2944,"thread_start_us":336,"threads_started":5,"update_count":2000}
I20260812 06:19:16.668406 21110 maintenance_manager.cc:419] P 6c90b85b007d4b3d87430ccd414f88ae: Scheduling FlushDeltaMemStoresOp(956c15bce98c48fcb032d12f9e74e345): perf score=10.126437
I20260812 06:19:16.701193 21033 maintenance_manager.cc:643] P 6c90b85b007d4b3d87430ccd414f88ae: FlushDeltaMemStoresOp(956c15bce98c48fcb032d12f9e74e345) complete. Timing: real 0.033s	user 0.022s	sys 0.008s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":14203,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:16.701711 21110 maintenance_manager.cc:419] P 6c90b85b007d4b3d87430ccd414f88ae: Scheduling FlushDeltaMemStoresOp(956c15bce98c48fcb032d12f9e74e345): perf score=2.188937
I20260812 06:19:16.720088 21033 maintenance_manager.cc:643] P 6c90b85b007d4b3d87430ccd414f88ae: FlushDeltaMemStoresOp(956c15bce98c48fcb032d12f9e74e345) complete. Timing: real 0.018s	user 0.008s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6249,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:16.720593 21110 maintenance_manager.cc:419] P 6c90b85b007d4b3d87430ccd414f88ae: Scheduling MajorDeltaCompactionOp(956c15bce98c48fcb032d12f9e74e345): perf score=1.000000
I20260812 06:19:16.838651 21033 maintenance_manager.cc:643] P 6c90b85b007d4b3d87430ccd414f88ae: MajorDeltaCompactionOp(956c15bce98c48fcb032d12f9e74e345) complete. Timing: real 0.118s	user 0.088s	sys 0.030s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631313,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":248,"lbm_read_time_us":6959,"lbm_reads_lt_1ms":464,"lbm_write_time_us":22654,"lbm_writes_lt_1ms":443,"mutex_wait_us":43,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":13824,"update_count":2000}
I20260812 06:19:16.839255 21110 maintenance_manager.cc:419] P 6c90b85b007d4b3d87430ccd414f88ae: Scheduling FlushDeltaMemStoresOp(956c15bce98c48fcb032d12f9e74e345): perf score=10.126437
I20260812 06:19:16.880374 21033 maintenance_manager.cc:643] P 6c90b85b007d4b3d87430ccd414f88ae: FlushDeltaMemStoresOp(956c15bce98c48fcb032d12f9e74e345) complete. Timing: real 0.041s	user 0.031s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17740,"lbm_writes_lt_1ms":303,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":1500}
I20260812 06:19:16.880892 21110 maintenance_manager.cc:419] P 6c90b85b007d4b3d87430ccd414f88ae: Scheduling FlushDeltaMemStoresOp(956c15bce98c48fcb032d12f9e74e345): perf score=2.188937
I20260812 06:19:16.892765 21033 maintenance_manager.cc:643] P 6c90b85b007d4b3d87430ccd414f88ae: FlushDeltaMemStoresOp(956c15bce98c48fcb032d12f9e74e345) complete. Timing: real 0.012s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4042,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:16.894014 21110 maintenance_manager.cc:419] P 6c90b85b007d4b3d87430ccd414f88ae: Scheduling MajorDeltaCompactionOp(956c15bce98c48fcb032d12f9e74e345): perf score=1.000000
I20260812 06:19:17.017185 21033 maintenance_manager.cc:643] P 6c90b85b007d4b3d87430ccd414f88ae: MajorDeltaCompactionOp(956c15bce98c48fcb032d12f9e74e345) complete. Timing: real 0.123s	user 0.090s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":977,"lbm_read_time_us":7759,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26231,"lbm_writes_lt_1ms":443,"mutex_wait_us":277,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11008,"update_count":2000}
I20260812 06:19:17.017822 21110 maintenance_manager.cc:419] P 6c90b85b007d4b3d87430ccd414f88ae: Scheduling FlushDeltaMemStoresOp(956c15bce98c48fcb032d12f9e74e345): perf score=10.126437
I20260812 06:19:17.068598 21033 maintenance_manager.cc:643] P 6c90b85b007d4b3d87430ccd414f88ae: FlushDeltaMemStoresOp(956c15bce98c48fcb032d12f9e74e345) complete. Timing: real 0.051s	user 0.016s	sys 0.022s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14149,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:17.069165 21110 maintenance_manager.cc:419] P 6c90b85b007d4b3d87430ccd414f88ae: Scheduling FlushDeltaMemStoresOp(956c15bce98c48fcb032d12f9e74e345): perf score=2.188937
I20260812 06:19:17.081182 21033 maintenance_manager.cc:643] P 6c90b85b007d4b3d87430ccd414f88ae: FlushDeltaMemStoresOp(956c15bce98c48fcb032d12f9e74e345) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4758,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:17.081686 21110 maintenance_manager.cc:419] P 6c90b85b007d4b3d87430ccd414f88ae: Scheduling MajorDeltaCompactionOp(956c15bce98c48fcb032d12f9e74e345): perf score=1.000000
I20260812 06:19:17.236725 21033 maintenance_manager.cc:643] P 6c90b85b007d4b3d87430ccd414f88ae: MajorDeltaCompactionOp(956c15bce98c48fcb032d12f9e74e345) complete. Timing: real 0.155s	user 0.110s	sys 0.044s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":542,"lbm_read_time_us":11681,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25994,"lbm_writes_lt_1ms":443,"mutex_wait_us":28,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4992,"update_count":2000}
I20260812 06:19:17.237254 21110 maintenance_manager.cc:419] P 6c90b85b007d4b3d87430ccd414f88ae: Scheduling FlushDeltaMemStoresOp(956c15bce98c48fcb032d12f9e74e345): perf score=10.126437
I20260812 06:19:17.267673 21033 maintenance_manager.cc:643] P 6c90b85b007d4b3d87430ccd414f88ae: FlushDeltaMemStoresOp(956c15bce98c48fcb032d12f9e74e345) complete. Timing: real 0.029s	user 0.014s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":13047,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:17.268182 21110 maintenance_manager.cc:419] P 6c90b85b007d4b3d87430ccd414f88ae: Scheduling FlushDeltaMemStoresOp(956c15bce98c48fcb032d12f9e74e345): perf score=2.188937
I20260812 06:19:17.279151 21033 maintenance_manager.cc:643] P 6c90b85b007d4b3d87430ccd414f88ae: FlushDeltaMemStoresOp(956c15bce98c48fcb032d12f9e74e345) complete. Timing: real 0.011s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4351,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:17.279762 21110 maintenance_manager.cc:419] P 6c90b85b007d4b3d87430ccd414f88ae: Scheduling MajorDeltaCompactionOp(956c15bce98c48fcb032d12f9e74e345): perf score=1.000000
I20260812 06:19:17.395450 21033 maintenance_manager.cc:643] P 6c90b85b007d4b3d87430ccd414f88ae: MajorDeltaCompactionOp(956c15bce98c48fcb032d12f9e74e345) complete. Timing: real 0.115s	user 0.095s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631312,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":188,"lbm_read_time_us":8824,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22167,"lbm_writes_lt_1ms":443,"mutex_wait_us":70,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7936,"update_count":2000}
I20260812 06:19:17.396160 21110 maintenance_manager.cc:419] P 6c90b85b007d4b3d87430ccd414f88ae: Scheduling FlushDeltaMemStoresOp(956c15bce98c48fcb032d12f9e74e345): perf score=10.126437
I20260812 06:19:17.433033 21033 maintenance_manager.cc:643] P 6c90b85b007d4b3d87430ccd414f88ae: FlushDeltaMemStoresOp(956c15bce98c48fcb032d12f9e74e345) complete. Timing: real 0.037s	user 0.026s	sys 0.009s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15956,"lbm_writes_lt_1ms":303,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":1500}
I20260812 06:19:17.433480 21110 maintenance_manager.cc:419] P 6c90b85b007d4b3d87430ccd414f88ae: Scheduling FlushDeltaMemStoresOp(956c15bce98c48fcb032d12f9e74e345): perf score=2.188937
I20260812 06:19:17.452567 21033 maintenance_manager.cc:643] P 6c90b85b007d4b3d87430ccd414f88ae: FlushDeltaMemStoresOp(956c15bce98c48fcb032d12f9e74e345) complete. Timing: real 0.019s	user 0.010s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6348,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:17.453020 21110 maintenance_manager.cc:419] P 6c90b85b007d4b3d87430ccd414f88ae: Scheduling MajorDeltaCompactionOp(956c15bce98c48fcb032d12f9e74e345): perf score=1.000000
I20260812 06:19:17.573747 21033 maintenance_manager.cc:643] P 6c90b85b007d4b3d87430ccd414f88ae: MajorDeltaCompactionOp(956c15bce98c48fcb032d12f9e74e345) complete. Timing: real 0.121s	user 0.095s	sys 0.026s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20631311,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":974,"lbm_read_time_us":6847,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24937,"lbm_writes_lt_1ms":443,"mutex_wait_us":338,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7552,"update_count":2000}
I20260812 06:19:17.574537 21110 maintenance_manager.cc:419] P 6c90b85b007d4b3d87430ccd414f88ae: Scheduling FlushDeltaMemStoresOp(956c15bce98c48fcb032d12f9e74e345): perf score=11.118625
I20260812 06:19:17.621501 21033 maintenance_manager.cc:643] P 6c90b85b007d4b3d87430ccd414f88ae: FlushDeltaMemStoresOp(956c15bce98c48fcb032d12f9e74e345) complete. Timing: real 0.047s	user 0.026s	sys 0.018s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":17951,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:17.622042 21110 maintenance_manager.cc:419] P 6c90b85b007d4b3d87430ccd414f88ae: Scheduling FlushDeltaMemStoresOp(956c15bce98c48fcb032d12f9e74e345): perf score=2.188937
I20260812 06:19:17.631825 21033 maintenance_manager.cc:643] P 6c90b85b007d4b3d87430ccd414f88ae: FlushDeltaMemStoresOp(956c15bce98c48fcb032d12f9e74e345) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3692,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:17.632273 21110 maintenance_manager.cc:419] P 6c90b85b007d4b3d87430ccd414f88ae: Scheduling FlushMRSOp(956c15bce98c48fcb032d12f9e74e345): perf score=1.000000
I20260812 06:19:17.671365 21033 maintenance_manager.cc:643] P 6c90b85b007d4b3d87430ccd414f88ae: FlushMRSOp(956c15bce98c48fcb032d12f9e74e345) complete. Timing: real 0.039s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1152509,"cfile_init":1,"dirs.queue_time_us":62,"dirs.run_cpu_time_us":274,"dirs.run_wall_time_us":1519,"drs_written":1,"lbm_read_time_us":66,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1593,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:19:17.672268 21110 maintenance_manager.cc:419] P 6c90b85b007d4b3d87430ccd414f88ae: Scheduling LogGCOp(956c15bce98c48fcb032d12f9e74e345): free 117302561 bytes of WAL
I20260812 06:19:17.672495 21033 log_reader.cc:385] T 956c15bce98c48fcb032d12f9e74e345: removed 12 log segments from log reader
I20260812 06:19:17.672539 21033 log.cc:1079] T 956c15bce98c48fcb032d12f9e74e345 P 6c90b85b007d4b3d87430ccd414f88ae: Deleting log segment in path: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515555931601-20911-0/minicluster-data/ts-0-root/wals/956c15bce98c48fcb032d12f9e74e345/wal-000000002 (ops 7-11)
I20260812 06:19:17.672569 21033 log.cc:1079] T 956c15bce98c48fcb032d12f9e74e345 P 6c90b85b007d4b3d87430ccd414f88ae: Deleting log segment in path: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515555931601-20911-0/minicluster-data/ts-0-root/wals/956c15bce98c48fcb032d12f9e74e345/wal-000000003 (ops 12-16)
I20260812 06:19:17.672636 21033 log.cc:1079] T 956c15bce98c48fcb032d12f9e74e345 P 6c90b85b007d4b3d87430ccd414f88ae: Deleting log segment in path: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515555931601-20911-0/minicluster-data/ts-0-root/wals/956c15bce98c48fcb032d12f9e74e345/wal-000000004 (ops 17-21)
I20260812 06:19:17.672679 21033 log.cc:1079] T 956c15bce98c48fcb032d12f9e74e345 P 6c90b85b007d4b3d87430ccd414f88ae: Deleting log segment in path: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515555931601-20911-0/minicluster-data/ts-0-root/wals/956c15bce98c48fcb032d12f9e74e345/wal-000000005 (ops 22-26)
I20260812 06:19:17.672720 21033 log.cc:1079] T 956c15bce98c48fcb032d12f9e74e345 P 6c90b85b007d4b3d87430ccd414f88ae: Deleting log segment in path: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515555931601-20911-0/minicluster-data/ts-0-root/wals/956c15bce98c48fcb032d12f9e74e345/wal-000000006 (ops 27-30)
I20260812 06:19:17.672746 21033 log.cc:1079] T 956c15bce98c48fcb032d12f9e74e345 P 6c90b85b007d4b3d87430ccd414f88ae: Deleting log segment in path: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515555931601-20911-0/minicluster-data/ts-0-root/wals/956c15bce98c48fcb032d12f9e74e345/wal-000000007 (ops 31-35)
I20260812 06:19:17.672784 21033 log.cc:1079] T 956c15bce98c48fcb032d12f9e74e345 P 6c90b85b007d4b3d87430ccd414f88ae: Deleting log segment in path: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515555931601-20911-0/minicluster-data/ts-0-root/wals/956c15bce98c48fcb032d12f9e74e345/wal-000000008 (ops 36-40)
I20260812 06:19:17.672820 21033 log.cc:1079] T 956c15bce98c48fcb032d12f9e74e345 P 6c90b85b007d4b3d87430ccd414f88ae: Deleting log segment in path: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515555931601-20911-0/minicluster-data/ts-0-root/wals/956c15bce98c48fcb032d12f9e74e345/wal-000000009 (ops 41-44)
I20260812 06:19:17.672848 21033 log.cc:1079] T 956c15bce98c48fcb032d12f9e74e345 P 6c90b85b007d4b3d87430ccd414f88ae: Deleting log segment in path: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515555931601-20911-0/minicluster-data/ts-0-root/wals/956c15bce98c48fcb032d12f9e74e345/wal-000000010 (ops 45-49)
I20260812 06:19:17.672876 21033 log.cc:1079] T 956c15bce98c48fcb032d12f9e74e345 P 6c90b85b007d4b3d87430ccd414f88ae: Deleting log segment in path: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515555931601-20911-0/minicluster-data/ts-0-root/wals/956c15bce98c48fcb032d12f9e74e345/wal-000000011 (ops 50-54)
I20260812 06:19:17.672904 21033 log.cc:1079] T 956c15bce98c48fcb032d12f9e74e345 P 6c90b85b007d4b3d87430ccd414f88ae: Deleting log segment in path: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515555931601-20911-0/minicluster-data/ts-0-root/wals/956c15bce98c48fcb032d12f9e74e345/wal-000000012 (ops 55-59)
I20260812 06:19:17.672945 21033 log.cc:1079] T 956c15bce98c48fcb032d12f9e74e345 P 6c90b85b007d4b3d87430ccd414f88ae: Deleting log segment in path: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515555931601-20911-0/minicluster-data/ts-0-root/wals/956c15bce98c48fcb032d12f9e74e345/wal-000000013 (ops 60-64)
I20260812 06:19:17.695003 21033 maintenance_manager.cc:643] P 6c90b85b007d4b3d87430ccd414f88ae: LogGCOp(956c15bce98c48fcb032d12f9e74e345) complete. Timing: real 0.023s	user 0.000s	sys 0.019s Metrics: {}
I20260812 06:19:17.695508 21110 maintenance_manager.cc:419] P 6c90b85b007d4b3d87430ccd414f88ae: Scheduling UndoDeltaBlockGCOp(956c15bce98c48fcb032d12f9e74e345): 448 bytes on disk
I20260812 06:19:17.695955 21033 maintenance_manager.cc:643] P 6c90b85b007d4b3d87430ccd414f88ae: UndoDeltaBlockGCOp(956c15bce98c48fcb032d12f9e74e345) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4}
I20260812 06:19:17.696408 21110 maintenance_manager.cc:419] P 6c90b85b007d4b3d87430ccd414f88ae: Scheduling FlushDeltaMemStoresOp(956c15bce98c48fcb032d12f9e74e345): perf score=2.188937
I20260812 06:19:17.719439 21033 maintenance_manager.cc:643] P 6c90b85b007d4b3d87430ccd414f88ae: FlushDeltaMemStoresOp(956c15bce98c48fcb032d12f9e74e345) complete. Timing: real 0.023s	user 0.002s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5457,"lbm_writes_lt_1ms":103,"mutex_wait_us":39,"reinsert_count":0,"update_count":500}
I20260812 06:19:17.719853 21110 maintenance_manager.cc:419] P 6c90b85b007d4b3d87430ccd414f88ae: Scheduling FlushDeltaMemStoresOp(956c15bce98c48fcb032d12f9e74e345): perf score=2.188937
I20260812 06:19:17.730213 21033 maintenance_manager.cc:643] P 6c90b85b007d4b3d87430ccd414f88ae: FlushDeltaMemStoresOp(956c15bce98c48fcb032d12f9e74e345) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3917,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:17.730662 21110 maintenance_manager.cc:419] P 6c90b85b007d4b3d87430ccd414f88ae: Scheduling MajorDeltaCompactionOp(956c15bce98c48fcb032d12f9e74e345): perf score=1.000000
I20260812 06:19:17.940196 21033 maintenance_manager.cc:643] P 6c90b85b007d4b3d87430ccd414f88ae: MajorDeltaCompactionOp(956c15bce98c48fcb032d12f9e74e345) complete. Timing: real 0.209s	user 0.147s	sys 0.060s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28836366,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":962,"lbm_read_time_us":13870,"lbm_reads_lt_1ms":674,"lbm_write_time_us":35241,"lbm_writes_lt_1ms":643,"mutex_wait_us":311,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":56192,"thread_start_us":125,"threads_started":1,"update_count":3000}
I20260812 06:19:17.940851 21110 maintenance_manager.cc:419] P 6c90b85b007d4b3d87430ccd414f88ae: Scheduling FlushDeltaMemStoresOp(956c15bce98c48fcb032d12f9e74e345): perf score=14.095187
I20260812 06:19:17.990715 21033 maintenance_manager.cc:643] P 6c90b85b007d4b3d87430ccd414f88ae: FlushDeltaMemStoresOp(956c15bce98c48fcb032d12f9e74e345) complete. Timing: real 0.050s	user 0.029s	sys 0.014s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22882,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:19:17.991366 21110 maintenance_manager.cc:419] P 6c90b85b007d4b3d87430ccd414f88ae: Scheduling FlushDeltaMemStoresOp(956c15bce98c48fcb032d12f9e74e345): perf score=1.000000
I20260812 06:19:17.998634 21033 maintenance_manager.cc:643] P 6c90b85b007d4b3d87430ccd414f88ae: FlushDeltaMemStoresOp(956c15bce98c48fcb032d12f9e74e345) complete. Timing: real 0.007s	user 0.004s	sys 0.000s Metrics: {"bytes_written":1600131,"delete_count":0,"lbm_write_time_us":1699,"lbm_writes_lt_1ms":42,"reinsert_count":0,"update_count":195}
I20260812 06:19:17.999119 21110 maintenance_manager.cc:419] P 6c90b85b007d4b3d87430ccd414f88ae: Scheduling FlushDeltaMemStoresOp(956c15bce98c48fcb032d12f9e74e345): perf score=1.196750
I20260812 06:19:18.006091 21033 maintenance_manager.cc:643] P 6c90b85b007d4b3d87430ccd414f88ae: FlushDeltaMemStoresOp(956c15bce98c48fcb032d12f9e74e345) complete. Timing: real 0.007s	user 0.005s	sys 0.000s Metrics: {"bytes_written":2502679,"delete_count":0,"lbm_write_time_us":2476,"lbm_writes_lt_1ms":64,"reinsert_count":0,"update_count":305}
I20260812 06:19:18.006493 21110 maintenance_manager.cc:419] P 6c90b85b007d4b3d87430ccd414f88ae: Scheduling MajorDeltaCompactionOp(956c15bce98c48fcb032d12f9e74e345): perf score=1.000000
I20260812 06:19:18.176250 21033 maintenance_manager.cc:643] P 6c90b85b007d4b3d87430ccd414f88ae: MajorDeltaCompactionOp(956c15bce98c48fcb032d12f9e74e345) complete. Timing: real 0.170s	user 0.087s	sys 0.080s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24733747,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":149,"lbm_read_time_us":13004,"lbm_reads_lt_1ms":573,"lbm_write_time_us":27823,"lbm_writes_lt_1ms":543,"mutex_wait_us":22,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12288,"update_count":2500}
I20260812 06:19:18.179394 21110 maintenance_manager.cc:419] P 6c90b85b007d4b3d87430ccd414f88ae: Scheduling FlushDeltaMemStoresOp(956c15bce98c48fcb032d12f9e74e345): perf score=14.095187
I20260812 06:19:18.234647 21033 maintenance_manager.cc:643] P 6c90b85b007d4b3d87430ccd414f88ae: FlushDeltaMemStoresOp(956c15bce98c48fcb032d12f9e74e345) complete. Timing: real 0.055s	user 0.043s	sys 0.006s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23069,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:18.235143 21110 maintenance_manager.cc:419] P 6c90b85b007d4b3d87430ccd414f88ae: Scheduling FlushDeltaMemStoresOp(956c15bce98c48fcb032d12f9e74e345): perf score=2.188937
I20260812 06:19:18.252452 21033 maintenance_manager.cc:643] P 6c90b85b007d4b3d87430ccd414f88ae: FlushDeltaMemStoresOp(956c15bce98c48fcb032d12f9e74e345) complete. Timing: real 0.017s	user 0.011s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6519,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:18.253058 21110 maintenance_manager.cc:419] P 6c90b85b007d4b3d87430ccd414f88ae: Scheduling MajorDeltaCompactionOp(956c15bce98c48fcb032d12f9e74e345): perf score=1.000000
I20260812 06:19:18.431459 21033 maintenance_manager.cc:643] P 6c90b85b007d4b3d87430ccd414f88ae: MajorDeltaCompactionOp(956c15bce98c48fcb032d12f9e74e345) complete. Timing: real 0.178s	user 0.118s	sys 0.060s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733724,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":195,"lbm_read_time_us":11796,"lbm_reads_lt_1ms":564,"lbm_write_time_us":32839,"lbm_writes_lt_1ms":543,"mutex_wait_us":20,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2432,"update_count":2500}
I20260812 06:19:18.432178 21110 maintenance_manager.cc:419] P 6c90b85b007d4b3d87430ccd414f88ae: Scheduling FlushDeltaMemStoresOp(956c15bce98c48fcb032d12f9e74e345): perf score=14.095187
I20260812 06:19:18.499279 21033 maintenance_manager.cc:643] P 6c90b85b007d4b3d87430ccd414f88ae: FlushDeltaMemStoresOp(956c15bce98c48fcb032d12f9e74e345) complete. Timing: real 0.067s	user 0.033s	sys 0.028s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23702,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:19:18.499794 21110 maintenance_manager.cc:419] P 6c90b85b007d4b3d87430ccd414f88ae: Scheduling FlushDeltaMemStoresOp(956c15bce98c48fcb032d12f9e74e345): perf score=2.188937
I20260812 06:19:18.511615 21033 maintenance_manager.cc:643] P 6c90b85b007d4b3d87430ccd414f88ae: FlushDeltaMemStoresOp(956c15bce98c48fcb032d12f9e74e345) complete. Timing: real 0.012s	user 0.011s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4660,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:18.512146 21110 maintenance_manager.cc:419] P 6c90b85b007d4b3d87430ccd414f88ae: Scheduling MajorDeltaCompactionOp(956c15bce98c48fcb032d12f9e74e345): perf score=1.000000
I20260812 06:19:18.699256 21033 maintenance_manager.cc:643] P 6c90b85b007d4b3d87430ccd414f88ae: MajorDeltaCompactionOp(956c15bce98c48fcb032d12f9e74e345) complete. Timing: real 0.187s	user 0.110s	sys 0.074s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733723,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":375,"lbm_read_time_us":12980,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34799,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":542,"mutex_wait_us":41,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:18.699959 21110 maintenance_manager.cc:419] P 6c90b85b007d4b3d87430ccd414f88ae: Scheduling FlushDeltaMemStoresOp(956c15bce98c48fcb032d12f9e74e345): perf score=14.095187
I20260812 06:19:18.742364 21033 maintenance_manager.cc:643] P 6c90b85b007d4b3d87430ccd414f88ae: FlushDeltaMemStoresOp(956c15bce98c48fcb032d12f9e74e345) complete. Timing: real 0.042s	user 0.012s	sys 0.026s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":18267,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:18.742882 21110 maintenance_manager.cc:419] P 6c90b85b007d4b3d87430ccd414f88ae: Scheduling FlushDeltaMemStoresOp(956c15bce98c48fcb032d12f9e74e345): perf score=2.188937
I20260812 06:19:18.768153 21033 maintenance_manager.cc:643] P 6c90b85b007d4b3d87430ccd414f88ae: FlushDeltaMemStoresOp(956c15bce98c48fcb032d12f9e74e345) complete. Timing: real 0.025s	user 0.013s	sys 0.011s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6079,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:18.768682 21110 maintenance_manager.cc:419] P 6c90b85b007d4b3d87430ccd414f88ae: Scheduling MajorDeltaCompactionOp(956c15bce98c48fcb032d12f9e74e345): perf score=1.000000
I20260812 06:19:18.961421 21033 maintenance_manager.cc:643] P 6c90b85b007d4b3d87430ccd414f88ae: MajorDeltaCompactionOp(956c15bce98c48fcb032d12f9e74e345) complete. Timing: real 0.192s	user 0.143s	sys 0.049s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733724,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":546,"lbm_read_time_us":14985,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29756,"lbm_writes_lt_1ms":543,"mutex_wait_us":244,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:18.962028 21110 maintenance_manager.cc:419] P 6c90b85b007d4b3d87430ccd414f88ae: Scheduling FlushDeltaMemStoresOp(956c15bce98c48fcb032d12f9e74e345): perf score=14.095187
I20260812 06:19:19.015916 21033 maintenance_manager.cc:643] P 6c90b85b007d4b3d87430ccd414f88ae: FlushDeltaMemStoresOp(956c15bce98c48fcb032d12f9e74e345) complete. Timing: real 0.054s	user 0.034s	sys 0.019s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":23141,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:19.016444 21110 maintenance_manager.cc:419] P 6c90b85b007d4b3d87430ccd414f88ae: Scheduling FlushDeltaMemStoresOp(956c15bce98c48fcb032d12f9e74e345): perf score=2.188937
I20260812 06:19:19.034492 21033 maintenance_manager.cc:643] P 6c90b85b007d4b3d87430ccd414f88ae: FlushDeltaMemStoresOp(956c15bce98c48fcb032d12f9e74e345) complete. Timing: real 0.018s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5038,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:19.035070 21110 maintenance_manager.cc:419] P 6c90b85b007d4b3d87430ccd414f88ae: Scheduling FlushMRSOp(956c15bce98c48fcb032d12f9e74e345): perf score=1.000000
I20260812 06:19:19.083621 21033 maintenance_manager.cc:643] P 6c90b85b007d4b3d87430ccd414f88ae: FlushMRSOp(956c15bce98c48fcb032d12f9e74e345) complete. Timing: real 0.048s	user 0.034s	sys 0.004s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":56,"dirs.run_cpu_time_us":238,"dirs.run_wall_time_us":1611,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1621,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:19:19.084328 21110 maintenance_manager.cc:419] P 6c90b85b007d4b3d87430ccd414f88ae: Scheduling LogGCOp(956c15bce98c48fcb032d12f9e74e345): free 108082405 bytes of WAL
I20260812 06:19:19.084565 21033 log_reader.cc:385] T 956c15bce98c48fcb032d12f9e74e345: removed 11 log segments from log reader
I20260812 06:19:19.084612 21033 log.cc:1079] T 956c15bce98c48fcb032d12f9e74e345 P 6c90b85b007d4b3d87430ccd414f88ae: Deleting log segment in path: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515555931601-20911-0/minicluster-data/ts-0-root/wals/956c15bce98c48fcb032d12f9e74e345/wal-000000014 (ops 65-68)
I20260812 06:19:19.084641 21033 log.cc:1079] T 956c15bce98c48fcb032d12f9e74e345 P 6c90b85b007d4b3d87430ccd414f88ae: Deleting log segment in path: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515555931601-20911-0/minicluster-data/ts-0-root/wals/956c15bce98c48fcb032d12f9e74e345/wal-000000015 (ops 69-73)
I20260812 06:19:19.084707 21033 log.cc:1079] T 956c15bce98c48fcb032d12f9e74e345 P 6c90b85b007d4b3d87430ccd414f88ae: Deleting log segment in path: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515555931601-20911-0/minicluster-data/ts-0-root/wals/956c15bce98c48fcb032d12f9e74e345/wal-000000016 (ops 74-78)
I20260812 06:19:19.084766 21033 log.cc:1079] T 956c15bce98c48fcb032d12f9e74e345 P 6c90b85b007d4b3d87430ccd414f88ae: Deleting log segment in path: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515555931601-20911-0/minicluster-data/ts-0-root/wals/956c15bce98c48fcb032d12f9e74e345/wal-000000017 (ops 79-82)
I20260812 06:19:19.084807 21033 log.cc:1079] T 956c15bce98c48fcb032d12f9e74e345 P 6c90b85b007d4b3d87430ccd414f88ae: Deleting log segment in path: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515555931601-20911-0/minicluster-data/ts-0-root/wals/956c15bce98c48fcb032d12f9e74e345/wal-000000018 (ops 83-87)
I20260812 06:19:19.084849 21033 log.cc:1079] T 956c15bce98c48fcb032d12f9e74e345 P 6c90b85b007d4b3d87430ccd414f88ae: Deleting log segment in path: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515555931601-20911-0/minicluster-data/ts-0-root/wals/956c15bce98c48fcb032d12f9e74e345/wal-000000019 (ops 88-92)
I20260812 06:19:19.084889 21033 log.cc:1079] T 956c15bce98c48fcb032d12f9e74e345 P 6c90b85b007d4b3d87430ccd414f88ae: Deleting log segment in path: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515555931601-20911-0/minicluster-data/ts-0-root/wals/956c15bce98c48fcb032d12f9e74e345/wal-000000020 (ops 93-97)
I20260812 06:19:19.084928 21033 log.cc:1079] T 956c15bce98c48fcb032d12f9e74e345 P 6c90b85b007d4b3d87430ccd414f88ae: Deleting log segment in path: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515555931601-20911-0/minicluster-data/ts-0-root/wals/956c15bce98c48fcb032d12f9e74e345/wal-000000021 (ops 98-102)
I20260812 06:19:19.084966 21033 log.cc:1079] T 956c15bce98c48fcb032d12f9e74e345 P 6c90b85b007d4b3d87430ccd414f88ae: Deleting log segment in path: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515555931601-20911-0/minicluster-data/ts-0-root/wals/956c15bce98c48fcb032d12f9e74e345/wal-000000022 (ops 103-106)
I20260812 06:19:19.085003 21033 log.cc:1079] T 956c15bce98c48fcb032d12f9e74e345 P 6c90b85b007d4b3d87430ccd414f88ae: Deleting log segment in path: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515555931601-20911-0/minicluster-data/ts-0-root/wals/956c15bce98c48fcb032d12f9e74e345/wal-000000023 (ops 107-111)
I20260812 06:19:19.085044 21033 log.cc:1079] T 956c15bce98c48fcb032d12f9e74e345 P 6c90b85b007d4b3d87430ccd414f88ae: Deleting log segment in path: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515555931601-20911-0/minicluster-data/ts-0-root/wals/956c15bce98c48fcb032d12f9e74e345/wal-000000024 (ops 112-116)
I20260812 06:19:19.106034 21033 maintenance_manager.cc:643] P 6c90b85b007d4b3d87430ccd414f88ae: LogGCOp(956c15bce98c48fcb032d12f9e74e345) complete. Timing: real 0.022s	user 0.000s	sys 0.019s Metrics: {}
I20260812 06:19:19.106516 21110 maintenance_manager.cc:419] P 6c90b85b007d4b3d87430ccd414f88ae: Scheduling UndoDeltaBlockGCOp(956c15bce98c48fcb032d12f9e74e345): 447 bytes on disk
I20260812 06:19:19.107019 21033 maintenance_manager.cc:643] P 6c90b85b007d4b3d87430ccd414f88ae: UndoDeltaBlockGCOp(956c15bce98c48fcb032d12f9e74e345) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":69,"lbm_reads_lt_1ms":4}
I20260812 06:19:19.107580 21110 maintenance_manager.cc:419] P 6c90b85b007d4b3d87430ccd414f88ae: Scheduling FlushDeltaMemStoresOp(956c15bce98c48fcb032d12f9e74e345): perf score=6.157687
I20260812 06:19:19.134938 21033 maintenance_manager.cc:643] P 6c90b85b007d4b3d87430ccd414f88ae: FlushDeltaMemStoresOp(956c15bce98c48fcb032d12f9e74e345) complete. Timing: real 0.027s	user 0.014s	sys 0.011s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":11719,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:19:19.135519 21110 maintenance_manager.cc:419] P 6c90b85b007d4b3d87430ccd414f88ae: Scheduling LogGCOp(956c15bce98c48fcb032d12f9e74e345): free 12017927 bytes of WAL
I20260812 06:19:19.135775 21033 log_reader.cc:385] T 956c15bce98c48fcb032d12f9e74e345: removed 1 log segments from log reader
I20260812 06:19:19.135843 21033 log.cc:1079] T 956c15bce98c48fcb032d12f9e74e345 P 6c90b85b007d4b3d87430ccd414f88ae: Deleting log segment in path: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515555931601-20911-0/minicluster-data/ts-0-root/wals/956c15bce98c48fcb032d12f9e74e345/wal-000000025 (ops 117-121)
I20260812 06:19:19.138182 21033 maintenance_manager.cc:643] P 6c90b85b007d4b3d87430ccd414f88ae: LogGCOp(956c15bce98c48fcb032d12f9e74e345) complete. Timing: real 0.002s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:19:19.138478 21110 maintenance_manager.cc:419] P 6c90b85b007d4b3d87430ccd414f88ae: Scheduling MajorDeltaCompactionOp(956c15bce98c48fcb032d12f9e74e345): perf score=1.000000
I20260812 06:19:19.358902 21033 maintenance_manager.cc:643] P 6c90b85b007d4b3d87430ccd414f88ae: MajorDeltaCompactionOp(956c15bce98c48fcb032d12f9e74e345) complete. Timing: real 0.220s	user 0.156s	sys 0.060s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":32938669,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":2075,"lbm_read_time_us":14765,"lbm_reads_lt_1ms":765,"lbm_write_time_us":35465,"lbm_writes_lt_1ms":743,"mutex_wait_us":1813,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":26112,"thread_start_us":75,"threads_started":1,"update_count":3500}
I20260812 06:19:19.359552 21110 maintenance_manager.cc:419] P 6c90b85b007d4b3d87430ccd414f88ae: Scheduling FlushDeltaMemStoresOp(956c15bce98c48fcb032d12f9e74e345): perf score=18.063937
I20260812 06:19:19.428964 21033 maintenance_manager.cc:643] P 6c90b85b007d4b3d87430ccd414f88ae: FlushDeltaMemStoresOp(956c15bce98c48fcb032d12f9e74e345) complete. Timing: real 0.069s	user 0.031s	sys 0.035s Metrics: {"bytes_written":20512314,"delete_count":0,"lbm_write_time_us":32313,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":502,"reinsert_count":0,"update_count":2500}
I20260812 06:19:19.429391 21110 maintenance_manager.cc:419] P 6c90b85b007d4b3d87430ccd414f88ae: Scheduling FlushDeltaMemStoresOp(956c15bce98c48fcb032d12f9e74e345): perf score=2.188937
I20260812 06:19:19.440670 21033 maintenance_manager.cc:643] P 6c90b85b007d4b3d87430ccd414f88ae: FlushDeltaMemStoresOp(956c15bce98c48fcb032d12f9e74e345) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3845,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:19.441432 21110 maintenance_manager.cc:419] P 6c90b85b007d4b3d87430ccd414f88ae: Scheduling MajorDeltaCompactionOp(956c15bce98c48fcb032d12f9e74e345): perf score=1.000000
I20260812 06:19:19.634498 21033 maintenance_manager.cc:643] P 6c90b85b007d4b3d87430ccd414f88ae: MajorDeltaCompactionOp(956c15bce98c48fcb032d12f9e74e345) complete. Timing: real 0.193s	user 0.129s	sys 0.064s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28836136,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":293,"lbm_read_time_us":11826,"lbm_reads_lt_1ms":672,"lbm_write_time_us":33779,"lbm_writes_lt_1ms":643,"mutex_wait_us":68,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":9344,"update_count":3000}
I20260812 06:19:19.635228 21110 maintenance_manager.cc:419] P 6c90b85b007d4b3d87430ccd414f88ae: Scheduling FlushDeltaMemStoresOp(956c15bce98c48fcb032d12f9e74e345): perf score=14.095187
I20260812 06:19:19.695592 21033 maintenance_manager.cc:643] P 6c90b85b007d4b3d87430ccd414f88ae: FlushDeltaMemStoresOp(956c15bce98c48fcb032d12f9e74e345) complete. Timing: real 0.060s	user 0.034s	sys 0.025s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":27079,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:19.696063 21110 maintenance_manager.cc:419] P 6c90b85b007d4b3d87430ccd414f88ae: Scheduling FlushDeltaMemStoresOp(956c15bce98c48fcb032d12f9e74e345): perf score=3.181125
I20260812 06:19:19.718348 21033 maintenance_manager.cc:643] P 6c90b85b007d4b3d87430ccd414f88ae: FlushDeltaMemStoresOp(956c15bce98c48fcb032d12f9e74e345) complete. Timing: real 0.022s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":6213,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:19.718791 21110 maintenance_manager.cc:419] P 6c90b85b007d4b3d87430ccd414f88ae: Scheduling FlushDeltaMemStoresOp(956c15bce98c48fcb032d12f9e74e345): perf score=2.188937
I20260812 06:19:19.728842 21033 maintenance_manager.cc:643] P 6c90b85b007d4b3d87430ccd414f88ae: FlushDeltaMemStoresOp(956c15bce98c48fcb032d12f9e74e345) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3788,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:19.729315 21110 maintenance_manager.cc:419] P 6c90b85b007d4b3d87430ccd414f88ae: Scheduling MajorDeltaCompactionOp(956c15bce98c48fcb032d12f9e74e345): perf score=1.000000
I20260812 06:19:19.928220 21033 maintenance_manager.cc:643] P 6c90b85b007d4b3d87430ccd414f88ae: MajorDeltaCompactionOp(956c15bce98c48fcb032d12f9e74e345) complete. Timing: real 0.199s	user 0.116s	sys 0.083s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28836243,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":268,"lbm_read_time_us":14181,"lbm_reads_lt_1ms":673,"lbm_write_time_us":32419,"lbm_writes_lt_1ms":643,"mutex_wait_us":56,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":4224,"update_count":3000}
I20260812 06:19:19.929018 21110 maintenance_manager.cc:419] P 6c90b85b007d4b3d87430ccd414f88ae: Scheduling FlushDeltaMemStoresOp(956c15bce98c48fcb032d12f9e74e345): perf score=15.087375
I20260812 06:19:19.981002 21033 maintenance_manager.cc:643] P 6c90b85b007d4b3d87430ccd414f88ae: FlushDeltaMemStoresOp(956c15bce98c48fcb032d12f9e74e345) complete. Timing: real 0.052s	user 0.030s	sys 0.019s Metrics: {"bytes_written":16820142,"delete_count":0,"lbm_write_time_us":23502,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":412,"reinsert_count":0,"update_count":2050}
I20260812 06:19:19.981688 21110 maintenance_manager.cc:419] P 6c90b85b007d4b3d87430ccd414f88ae: Scheduling FlushDeltaMemStoresOp(956c15bce98c48fcb032d12f9e74e345): perf score=2.188937
I20260812 06:19:19.998121 21033 maintenance_manager.cc:643] P 6c90b85b007d4b3d87430ccd414f88ae: FlushDeltaMemStoresOp(956c15bce98c48fcb032d12f9e74e345) complete. Timing: real 0.016s	user 0.009s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5904,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:19.998620 21110 maintenance_manager.cc:419] P 6c90b85b007d4b3d87430ccd414f88ae: Scheduling MajorDeltaCompactionOp(956c15bce98c48fcb032d12f9e74e345): perf score=1.000000
I20260812 06:19:20.167174 21033 maintenance_manager.cc:643] P 6c90b85b007d4b3d87430ccd414f88ae: MajorDeltaCompactionOp(956c15bce98c48fcb032d12f9e74e345) complete. Timing: real 0.168s	user 0.108s	sys 0.060s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733710,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":236,"lbm_read_time_us":11114,"lbm_reads_lt_1ms":564,"lbm_write_time_us":29391,"lbm_writes_lt_1ms":543,"mutex_wait_us":43,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:19:20.167919 21110 maintenance_manager.cc:419] P 6c90b85b007d4b3d87430ccd414f88ae: Scheduling FlushDeltaMemStoresOp(956c15bce98c48fcb032d12f9e74e345): perf score=14.095187
I20260812 06:19:20.221450 21033 maintenance_manager.cc:643] P 6c90b85b007d4b3d87430ccd414f88ae: FlushDeltaMemStoresOp(956c15bce98c48fcb032d12f9e74e345) complete. Timing: real 0.053s	user 0.019s	sys 0.032s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":24233,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:20.222072 21110 maintenance_manager.cc:419] P 6c90b85b007d4b3d87430ccd414f88ae: Scheduling FlushDeltaMemStoresOp(956c15bce98c48fcb032d12f9e74e345): perf score=2.188937
I20260812 06:19:20.239864 21033 maintenance_manager.cc:643] P 6c90b85b007d4b3d87430ccd414f88ae: FlushDeltaMemStoresOp(956c15bce98c48fcb032d12f9e74e345) complete. Timing: real 0.018s	user 0.015s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6274,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:20.240408 21110 maintenance_manager.cc:419] P 6c90b85b007d4b3d87430ccd414f88ae: Scheduling MajorDeltaCompactionOp(956c15bce98c48fcb032d12f9e74e345): perf score=1.000000
I20260812 06:19:20.416847 21033 maintenance_manager.cc:643] P 6c90b85b007d4b3d87430ccd414f88ae: MajorDeltaCompactionOp(956c15bce98c48fcb032d12f9e74e345) complete. Timing: real 0.176s	user 0.129s	sys 0.047s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24733721,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":232,"lbm_read_time_us":11022,"lbm_reads_lt_1ms":564,"lbm_write_time_us":31372,"lbm_writes_lt_1ms":543,"mutex_wait_us":19,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8832,"update_count":2500}
I20260812 06:19:20.417516 21110 maintenance_manager.cc:419] P 6c90b85b007d4b3d87430ccd414f88ae: Scheduling FlushDeltaMemStoresOp(956c15bce98c48fcb032d12f9e74e345): perf score=14.095187
I20260812 06:19:20.483126 21033 maintenance_manager.cc:643] P 6c90b85b007d4b3d87430ccd414f88ae: FlushDeltaMemStoresOp(956c15bce98c48fcb032d12f9e74e345) complete. Timing: real 0.065s	user 0.025s	sys 0.032s Metrics: {"bytes_written":16409898,"delete_count":0,"lbm_write_time_us":24562,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:20.483620 21110 maintenance_manager.cc:419] P 6c90b85b007d4b3d87430ccd414f88ae: Scheduling FlushDeltaMemStoresOp(956c15bce98c48fcb032d12f9e74e345): perf score=2.188937
I20260812 06:19:20.498553 21033 maintenance_manager.cc:643] P 6c90b85b007d4b3d87430ccd414f88ae: FlushDeltaMemStoresOp(956c15bce98c48fcb032d12f9e74e345) complete. Timing: real 0.015s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4606,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:20.498998 21110 maintenance_manager.cc:419] P 6c90b85b007d4b3d87430ccd414f88ae: Scheduling FlushDeltaMemStoresOp(956c15bce98c48fcb032d12f9e74e345): perf score=2.188937
I20260812 06:19:20.509586 21033 maintenance_manager.cc:643] P 6c90b85b007d4b3d87430ccd414f88ae: FlushDeltaMemStoresOp(956c15bce98c48fcb032d12f9e74e345) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4188,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:20.510041 21110 maintenance_manager.cc:419] P 6c90b85b007d4b3d87430ccd414f88ae: Scheduling FlushMRSOp(956c15bce98c48fcb032d12f9e74e345): perf score=1.000000
I20260812 06:19:20.544380 21033 maintenance_manager.cc:643] P 6c90b85b007d4b3d87430ccd414f88ae: FlushMRSOp(956c15bce98c48fcb032d12f9e74e345) complete. Timing: real 0.034s	user 0.027s	sys 0.003s Metrics: {"bytes_written":1193506,"cfile_init":1,"dirs.queue_time_us":61,"dirs.run_cpu_time_us":144,"dirs.run_wall_time_us":1379,"drs_written":1,"lbm_read_time_us":62,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2079,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:20.545082 21110 maintenance_manager.cc:419] P 6c90b85b007d4b3d87430ccd414f88ae: Scheduling LogGCOp(956c15bce98c48fcb032d12f9e74e345): free 112239468 bytes of WAL
I20260812 06:19:20.545310 21033 log_reader.cc:385] T 956c15bce98c48fcb032d12f9e74e345: removed 11 log segments from log reader
I20260812 06:19:20.545354 21033 log.cc:1079] T 956c15bce98c48fcb032d12f9e74e345 P 6c90b85b007d4b3d87430ccd414f88ae: Deleting log segment in path: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515555931601-20911-0/minicluster-data/ts-0-root/wals/956c15bce98c48fcb032d12f9e74e345/wal-000000026 (ops 122-126)
I20260812 06:19:20.545382 21033 log.cc:1079] T 956c15bce98c48fcb032d12f9e74e345 P 6c90b85b007d4b3d87430ccd414f88ae: Deleting log segment in path: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515555931601-20911-0/minicluster-data/ts-0-root/wals/956c15bce98c48fcb032d12f9e74e345/wal-000000027 (ops 127-131)
I20260812 06:19:20.545444 21033 log.cc:1079] T 956c15bce98c48fcb032d12f9e74e345 P 6c90b85b007d4b3d87430ccd414f88ae: Deleting log segment in path: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515555931601-20911-0/minicluster-data/ts-0-root/wals/956c15bce98c48fcb032d12f9e74e345/wal-000000028 (ops 132-136)
I20260812 06:19:20.545490 21033 log.cc:1079] T 956c15bce98c48fcb032d12f9e74e345 P 6c90b85b007d4b3d87430ccd414f88ae: Deleting log segment in path: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515555931601-20911-0/minicluster-data/ts-0-root/wals/956c15bce98c48fcb032d12f9e74e345/wal-000000029 (ops 137-140)
I20260812 06:19:20.545531 21033 log.cc:1079] T 956c15bce98c48fcb032d12f9e74e345 P 6c90b85b007d4b3d87430ccd414f88ae: Deleting log segment in path: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515555931601-20911-0/minicluster-data/ts-0-root/wals/956c15bce98c48fcb032d12f9e74e345/wal-000000030 (ops 141-145)
I20260812 06:19:20.545573 21033 log.cc:1079] T 956c15bce98c48fcb032d12f9e74e345 P 6c90b85b007d4b3d87430ccd414f88ae: Deleting log segment in path: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515555931601-20911-0/minicluster-data/ts-0-root/wals/956c15bce98c48fcb032d12f9e74e345/wal-000000031 (ops 146-150)
I20260812 06:19:20.545619 21033 log.cc:1079] T 956c15bce98c48fcb032d12f9e74e345 P 6c90b85b007d4b3d87430ccd414f88ae: Deleting log segment in path: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515555931601-20911-0/minicluster-data/ts-0-root/wals/956c15bce98c48fcb032d12f9e74e345/wal-000000032 (ops 151-155)
I20260812 06:19:20.545661 21033 log.cc:1079] T 956c15bce98c48fcb032d12f9e74e345 P 6c90b85b007d4b3d87430ccd414f88ae: Deleting log segment in path: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515555931601-20911-0/minicluster-data/ts-0-root/wals/956c15bce98c48fcb032d12f9e74e345/wal-000000033 (ops 156-160)
I20260812 06:19:20.545701 21033 log.cc:1079] T 956c15bce98c48fcb032d12f9e74e345 P 6c90b85b007d4b3d87430ccd414f88ae: Deleting log segment in path: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515555931601-20911-0/minicluster-data/ts-0-root/wals/956c15bce98c48fcb032d12f9e74e345/wal-000000034 (ops 161-165)
I20260812 06:19:20.545742 21033 log.cc:1079] T 956c15bce98c48fcb032d12f9e74e345 P 6c90b85b007d4b3d87430ccd414f88ae: Deleting log segment in path: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515555931601-20911-0/minicluster-data/ts-0-root/wals/956c15bce98c48fcb032d12f9e74e345/wal-000000035 (ops 166-170)
I20260812 06:19:20.545781 21033 log.cc:1079] T 956c15bce98c48fcb032d12f9e74e345 P 6c90b85b007d4b3d87430ccd414f88ae: Deleting log segment in path: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515555931601-20911-0/minicluster-data/ts-0-root/wals/956c15bce98c48fcb032d12f9e74e345/wal-000000036 (ops 171-175)
I20260812 06:19:20.568636 21033 maintenance_manager.cc:643] P 6c90b85b007d4b3d87430ccd414f88ae: LogGCOp(956c15bce98c48fcb032d12f9e74e345) complete. Timing: real 0.023s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:19:20.569235 21110 maintenance_manager.cc:419] P 6c90b85b007d4b3d87430ccd414f88ae: Scheduling UndoDeltaBlockGCOp(956c15bce98c48fcb032d12f9e74e345): 462 bytes on disk
I20260812 06:19:20.569799 21033 maintenance_manager.cc:643] P 6c90b85b007d4b3d87430ccd414f88ae: UndoDeltaBlockGCOp(956c15bce98c48fcb032d12f9e74e345) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":67,"lbm_reads_lt_1ms":4}
I20260812 06:19:20.570590 21110 maintenance_manager.cc:419] P 6c90b85b007d4b3d87430ccd414f88ae: Scheduling FlushDeltaMemStoresOp(956c15bce98c48fcb032d12f9e74e345): perf score=2.188937
I20260812 06:19:20.586619 21033 maintenance_manager.cc:643] P 6c90b85b007d4b3d87430ccd414f88ae: FlushDeltaMemStoresOp(956c15bce98c48fcb032d12f9e74e345) complete. Timing: real 0.016s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4225731,"delete_count":0,"lbm_write_time_us":4462,"lbm_writes_lt_1ms":106,"mutex_wait_us":191,"reinsert_count":0,"update_count":515}
I20260812 06:19:20.587044 21110 maintenance_manager.cc:419] P 6c90b85b007d4b3d87430ccd414f88ae: Scheduling LogGCOp(956c15bce98c48fcb032d12f9e74e345): free 12018006 bytes of WAL
I20260812 06:19:20.587282 21033 log_reader.cc:385] T 956c15bce98c48fcb032d12f9e74e345: removed 1 log segments from log reader
I20260812 06:19:20.587325 21033 log.cc:1079] T 956c15bce98c48fcb032d12f9e74e345 P 6c90b85b007d4b3d87430ccd414f88ae: Deleting log segment in path: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515555931601-20911-0/minicluster-data/ts-0-root/wals/956c15bce98c48fcb032d12f9e74e345/wal-000000037 (ops 176-180)
I20260812 06:19:20.589757 21033 maintenance_manager.cc:643] P 6c90b85b007d4b3d87430ccd414f88ae: LogGCOp(956c15bce98c48fcb032d12f9e74e345) complete. Timing: real 0.003s	user 0.000s	sys 0.000s Metrics: {}
I20260812 06:19:20.590034 21110 maintenance_manager.cc:419] P 6c90b85b007d4b3d87430ccd414f88ae: Scheduling FlushDeltaMemStoresOp(956c15bce98c48fcb032d12f9e74e345): perf score=2.188937
I20260812 06:19:20.602100 21033 maintenance_manager.cc:643] P 6c90b85b007d4b3d87430ccd414f88ae: FlushDeltaMemStoresOp(956c15bce98c48fcb032d12f9e74e345) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":3979584,"delete_count":0,"lbm_write_time_us":4245,"lbm_writes_lt_1ms":100,"reinsert_count":0,"update_count":485}
I20260812 06:19:20.602735 21110 maintenance_manager.cc:419] P 6c90b85b007d4b3d87430ccd414f88ae: Scheduling MajorDeltaCompactionOp(956c15bce98c48fcb032d12f9e74e345): perf score=1.000000
I20260812 06:19:20.849295 21033 maintenance_manager.cc:643] P 6c90b85b007d4b3d87430ccd414f88ae: MajorDeltaCompactionOp(956c15bce98c48fcb032d12f9e74e345) complete. Timing: real 0.246s	user 0.170s	sys 0.076s Metrics: {"cfile_cache_miss":835,"cfile_cache_miss_bytes":37041310,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":566,"lbm_read_time_us":19825,"lbm_reads_lt_1ms":875,"lbm_write_time_us":44719,"lbm_writes_lt_1ms":843,"mutex_wait_us":22,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":11136,"thread_start_us":80,"threads_started":1,"update_count":4000}
I20260812 06:19:20.850144 21110 maintenance_manager.cc:419] P 6c90b85b007d4b3d87430ccd414f88ae: Scheduling FlushDeltaMemStoresOp(956c15bce98c48fcb032d12f9e74e345): perf score=18.063937
I20260812 06:19:20.906844 21033 maintenance_manager.cc:643] P 6c90b85b007d4b3d87430ccd414f88ae: FlushDeltaMemStoresOp(956c15bce98c48fcb032d12f9e74e345) complete. Timing: real 0.056s	user 0.021s	sys 0.032s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":25129,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:20.907435 21110 maintenance_manager.cc:419] P 6c90b85b007d4b3d87430ccd414f88ae: Scheduling FlushDeltaMemStoresOp(956c15bce98c48fcb032d12f9e74e345): perf score=2.188937
I20260812 06:19:20.926086 21033 maintenance_manager.cc:643] P 6c90b85b007d4b3d87430ccd414f88ae: FlushDeltaMemStoresOp(956c15bce98c48fcb032d12f9e74e345) complete. Timing: real 0.018s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6135,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:20.926635 21110 maintenance_manager.cc:419] P 6c90b85b007d4b3d87430ccd414f88ae: Scheduling MajorDeltaCompactionOp(956c15bce98c48fcb032d12f9e74e345): perf score=1.000000
I20260812 06:19:21.068859 20911 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.837s	user 1.827s	sys 0.118s
I20260812 06:19:21.084793 21033 maintenance_manager.cc:643] P 6c90b85b007d4b3d87430ccd414f88ae: MajorDeltaCompactionOp(956c15bce98c48fcb032d12f9e74e345) complete. Timing: real 0.158s	user 0.120s	sys 0.036s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28836137,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"lbm_read_time_us":10510,"lbm_reads_lt_1ms":660,"lbm_write_time_us":34090,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"update_count":3000}
I20260812 06:19:21.085275 21110 maintenance_manager.cc:419] P 6c90b85b007d4b3d87430ccd414f88ae: Scheduling FlushDeltaMemStoresOp(956c15bce98c48fcb032d12f9e74e345): perf score=14.095187
I20260812 06:19:21.120348 21033 maintenance_manager.cc:643] P 6c90b85b007d4b3d87430ccd414f88ae: FlushDeltaMemStoresOp(956c15bce98c48fcb032d12f9e74e345) complete. Timing: real 0.035s	user 0.019s	sys 0.015s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":16866,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2000}
I20260812 06:19:21.120935 21110 maintenance_manager.cc:419] P 6c90b85b007d4b3d87430ccd414f88ae: Scheduling MajorDeltaCompactionOp(956c15bce98c48fcb032d12f9e74e345): perf score=1.000000
I20260812 06:19:21.139719 20911 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.070s	user 0.003s	sys 0.000s
I20260812 06:19:21.140376 20911 tablet_server.cc:179] TabletServer@127.20.107.193:0 shutting down...
I20260812 06:19:21.230618 21033 maintenance_manager.cc:643] P 6c90b85b007d4b3d87430ccd414f88ae: MajorDeltaCompactionOp(956c15bce98c48fcb032d12f9e74e345) complete. Timing: real 0.109s	user 0.084s	sys 0.024s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20631195,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":474,"lbm_read_time_us":8566,"lbm_reads_lt_1ms":467,"lbm_write_time_us":23423,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":442,"mutex_wait_us":132,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:21.231343 20911 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:21.231761 20911 tablet_replica.cc:333] T 956c15bce98c48fcb032d12f9e74e345 P 6c90b85b007d4b3d87430ccd414f88ae: stopping tablet replica
I20260812 06:19:21.232002 20911 raft_consensus.cc:2243] T 956c15bce98c48fcb032d12f9e74e345 P 6c90b85b007d4b3d87430ccd414f88ae [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:21.232230 20911 raft_consensus.cc:2272] T 956c15bce98c48fcb032d12f9e74e345 P 6c90b85b007d4b3d87430ccd414f88ae [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:21.236915 20911 tablet_server.cc:196] TabletServer@127.20.107.193:0 shutdown complete.
I20260812 06:19:21.271565 20911 master.cc:562] Master@127.20.107.254:45769 shutting down...
I20260812 06:19:21.275249 20911 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 32ef45e6cc80484f8d917f64d4f60789 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:21.275398 20911 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 32ef45e6cc80484f8d917f64d4f60789 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:21.275460 20911 tablet_replica.cc:333] T 00000000000000000000000000000000 P 32ef45e6cc80484f8d917f64d4f60789: stopping tablet replica
I20260812 06:19:21.287642 20911 master.cc:584] Master@127.20.107.254:45769 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5433 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:19:21.388037 20911 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.20.107.254:44665
I20260812 06:19:21.388403 20911 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:21.390412 21146 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:21.390484 21149 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:21.390475 21147 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:21.390542 20911 server_base.cc:1061] running on GCE node
I20260812 06:19:21.390830 20911 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:21.390892 20911 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:21.390923 20911 hybrid_clock.cc:648] HybridClock initialized: now 1786515561390923 us; error 0 us; skew 500 ppm
I20260812 06:19:21.391842 20911 webserver.cc:533] Webserver started at http://127.20.107.254:41429/ using document root <none> and password file <none>
I20260812 06:19:21.392020 20911 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:21.392091 20911 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:21.392169 20911 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:21.392582 20911 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515555931601-20911-0/minicluster-data/master-0-root/instance:
uuid: "fb15ec257f4144e58d6bca7730bcfac4"
format_stamp: "Formatted at 2026-08-12 06:19:21 on dist-test-slave-vkjp"
I20260812 06:19:21.394100 20911 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:21.395013 21154 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:21.395313 20911 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:21.395385 20911 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515555931601-20911-0/minicluster-data/master-0-root
uuid: "fb15ec257f4144e58d6bca7730bcfac4"
format_stamp: "Formatted at 2026-08-12 06:19:21 on dist-test-slave-vkjp"
I20260812 06:19:21.395439 20911 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515555931601-20911-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515555931601-20911-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515555931601-20911-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:21.408830 20911 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:21.409139 20911 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:21.412941 20911 rpc_server.cc:307] RPC server started. Bound to: 127.20.107.254:44665
I20260812 06:19:21.417466 21218 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.20.107.254:44665 every 8 connection(s)
I20260812 06:19:21.417979 21220 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:21.419799 21220 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P fb15ec257f4144e58d6bca7730bcfac4: Bootstrap starting.
I20260812 06:19:21.420557 21220 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P fb15ec257f4144e58d6bca7730bcfac4: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:21.421566 21220 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P fb15ec257f4144e58d6bca7730bcfac4: No bootstrap required, opened a new log
I20260812 06:19:21.421954 21220 raft_consensus.cc:359] T 00000000000000000000000000000000 P fb15ec257f4144e58d6bca7730bcfac4 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "fb15ec257f4144e58d6bca7730bcfac4" member_type: VOTER }
I20260812 06:19:21.422062 21220 raft_consensus.cc:385] T 00000000000000000000000000000000 P fb15ec257f4144e58d6bca7730bcfac4 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:21.422114 21220 raft_consensus.cc:740] T 00000000000000000000000000000000 P fb15ec257f4144e58d6bca7730bcfac4 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: fb15ec257f4144e58d6bca7730bcfac4, State: Initialized, Role: FOLLOWER
I20260812 06:19:21.422271 21220 consensus_queue.cc:260] T 00000000000000000000000000000000 P fb15ec257f4144e58d6bca7730bcfac4 [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: "fb15ec257f4144e58d6bca7730bcfac4" member_type: VOTER }
I20260812 06:19:21.422362 21220 raft_consensus.cc:399] T 00000000000000000000000000000000 P fb15ec257f4144e58d6bca7730bcfac4 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:21.422410 21220 raft_consensus.cc:493] T 00000000000000000000000000000000 P fb15ec257f4144e58d6bca7730bcfac4 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:21.422477 21220 raft_consensus.cc:3060] T 00000000000000000000000000000000 P fb15ec257f4144e58d6bca7730bcfac4 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:21.423158 21220 raft_consensus.cc:515] T 00000000000000000000000000000000 P fb15ec257f4144e58d6bca7730bcfac4 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "fb15ec257f4144e58d6bca7730bcfac4" member_type: VOTER }
I20260812 06:19:21.423303 21220 leader_election.cc:304] T 00000000000000000000000000000000 P fb15ec257f4144e58d6bca7730bcfac4 [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: fb15ec257f4144e58d6bca7730bcfac4; no voters: 
I20260812 06:19:21.423506 21220 leader_election.cc:290] T 00000000000000000000000000000000 P fb15ec257f4144e58d6bca7730bcfac4 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:21.423619 21224 raft_consensus.cc:2804] T 00000000000000000000000000000000 P fb15ec257f4144e58d6bca7730bcfac4 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:21.423856 21224 raft_consensus.cc:697] T 00000000000000000000000000000000 P fb15ec257f4144e58d6bca7730bcfac4 [term 1 LEADER]: Becoming Leader. State: Replica: fb15ec257f4144e58d6bca7730bcfac4, State: Running, Role: LEADER
I20260812 06:19:21.423961 21220 sys_catalog.cc:565] T 00000000000000000000000000000000 P fb15ec257f4144e58d6bca7730bcfac4 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:21.424003 21224 consensus_queue.cc:237] T 00000000000000000000000000000000 P fb15ec257f4144e58d6bca7730bcfac4 [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: "fb15ec257f4144e58d6bca7730bcfac4" member_type: VOTER }
I20260812 06:19:21.424417 21225 sys_catalog.cc:455] T 00000000000000000000000000000000 P fb15ec257f4144e58d6bca7730bcfac4 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "fb15ec257f4144e58d6bca7730bcfac4" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "fb15ec257f4144e58d6bca7730bcfac4" member_type: VOTER } }
I20260812 06:19:21.424450 21226 sys_catalog.cc:455] T 00000000000000000000000000000000 P fb15ec257f4144e58d6bca7730bcfac4 [sys.catalog]: SysCatalogTable state changed. Reason: New leader fb15ec257f4144e58d6bca7730bcfac4. Latest consensus state: current_term: 1 leader_uuid: "fb15ec257f4144e58d6bca7730bcfac4" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "fb15ec257f4144e58d6bca7730bcfac4" member_type: VOTER } }
I20260812 06:19:21.424504 21225 sys_catalog.cc:458] T 00000000000000000000000000000000 P fb15ec257f4144e58d6bca7730bcfac4 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:21.424537 21226 sys_catalog.cc:458] T 00000000000000000000000000000000 P fb15ec257f4144e58d6bca7730bcfac4 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:21.424732 21229 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:21.425626 21229 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:21.425827 20911 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:21.427440 21229 catalog_manager.cc:1383] Generated new cluster ID: c5516f5c166149a39a1fe04f81e45f56
I20260812 06:19:21.427506 21229 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:21.448945 21229 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:21.449488 21229 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:21.455395 21229 catalog_manager.cc:6092] T 00000000000000000000000000000000 P fb15ec257f4144e58d6bca7730bcfac4: Generated new TSK 0
I20260812 06:19:21.455555 21229 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:21.458045 20911 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:21.459903 21249 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:21.460028 21252 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:21.460074 21250 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:21.460209 20911 server_base.cc:1061] running on GCE node
I20260812 06:19:21.460469 20911 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:21.460516 20911 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:21.460532 20911 hybrid_clock.cc:648] HybridClock initialized: now 1786515561460532 us; error 0 us; skew 500 ppm
I20260812 06:19:21.461330 20911 webserver.cc:533] Webserver started at http://127.20.107.193:45843/ using document root <none> and password file <none>
I20260812 06:19:21.461470 20911 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:21.461514 20911 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:21.461565 20911 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:21.461894 20911 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515555931601-20911-0/minicluster-data/ts-0-root/instance:
uuid: "75fb46b29f24499b9ad90abf7891be61"
format_stamp: "Formatted at 2026-08-12 06:19:21 on dist-test-slave-vkjp"
I20260812 06:19:21.463325 20911 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:21.464183 21257 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:21.464426 20911 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:21.464522 20911 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515555931601-20911-0/minicluster-data/ts-0-root
uuid: "75fb46b29f24499b9ad90abf7891be61"
format_stamp: "Formatted at 2026-08-12 06:19:21 on dist-test-slave-vkjp"
I20260812 06:19:21.464607 20911 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515555931601-20911-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515555931601-20911-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515555931601-20911-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:21.496474 20911 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:21.496870 20911 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:21.497208 20911 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:21.497699 20911 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:21.497761 20911 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:21.497813 20911 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:21.497865 20911 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:21.502130 20911 rpc_server.cc:307] RPC server started. Bound to: 127.20.107.193:33113
I20260812 06:19:21.503784 21326 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.20.107.193:33113 every 8 connection(s)
I20260812 06:19:21.512167 21327 heartbeater.cc:344] Connected to a master server at 127.20.107.254:44665
I20260812 06:19:21.512271 21327 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:21.512460 21327 heartbeater.cc:507] Master 127.20.107.254:44665 requested a full tablet report, sending...
I20260812 06:19:21.513068 21177 ts_manager.cc:194] Registered new tserver with Master: 75fb46b29f24499b9ad90abf7891be61 (127.20.107.193:33113)
I20260812 06:19:21.513139 20911 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.009928379s
I20260812 06:19:21.513875 21177 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:33548
I20260812 06:19:21.520110 21177 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:33552:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:19:21.528919 21288 tablet_service.cc:1511] Processing CreateTablet for tablet b46b8f828a974a6f8127ecfc403ec57e (DEFAULT_TABLE table=heavy-update-compaction-test [id=5e993ac6fd424178b368b6afa59d3a1d]), partition=
I20260812 06:19:21.529210 21288 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet b46b8f828a974a6f8127ecfc403ec57e. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:21.531205 21341 tablet_bootstrap.cc:492] T b46b8f828a974a6f8127ecfc403ec57e P 75fb46b29f24499b9ad90abf7891be61: Bootstrap starting.
I20260812 06:19:21.531977 21341 tablet_bootstrap.cc:654] T b46b8f828a974a6f8127ecfc403ec57e P 75fb46b29f24499b9ad90abf7891be61: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:21.532871 21341 tablet_bootstrap.cc:492] T b46b8f828a974a6f8127ecfc403ec57e P 75fb46b29f24499b9ad90abf7891be61: No bootstrap required, opened a new log
I20260812 06:19:21.532943 21341 ts_tablet_manager.cc:1403] T b46b8f828a974a6f8127ecfc403ec57e P 75fb46b29f24499b9ad90abf7891be61: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:19:21.533258 21341 raft_consensus.cc:359] T b46b8f828a974a6f8127ecfc403ec57e P 75fb46b29f24499b9ad90abf7891be61 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "75fb46b29f24499b9ad90abf7891be61" member_type: VOTER last_known_addr { host: "127.20.107.193" port: 33113 } }
I20260812 06:19:21.533341 21341 raft_consensus.cc:385] T b46b8f828a974a6f8127ecfc403ec57e P 75fb46b29f24499b9ad90abf7891be61 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:21.533363 21341 raft_consensus.cc:740] T b46b8f828a974a6f8127ecfc403ec57e P 75fb46b29f24499b9ad90abf7891be61 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 75fb46b29f24499b9ad90abf7891be61, State: Initialized, Role: FOLLOWER
I20260812 06:19:21.533504 21341 consensus_queue.cc:260] T b46b8f828a974a6f8127ecfc403ec57e P 75fb46b29f24499b9ad90abf7891be61 [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: "75fb46b29f24499b9ad90abf7891be61" member_type: VOTER last_known_addr { host: "127.20.107.193" port: 33113 } }
I20260812 06:19:21.533595 21341 raft_consensus.cc:399] T b46b8f828a974a6f8127ecfc403ec57e P 75fb46b29f24499b9ad90abf7891be61 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:21.533622 21341 raft_consensus.cc:493] T b46b8f828a974a6f8127ecfc403ec57e P 75fb46b29f24499b9ad90abf7891be61 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:21.533656 21341 raft_consensus.cc:3060] T b46b8f828a974a6f8127ecfc403ec57e P 75fb46b29f24499b9ad90abf7891be61 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:21.534569 21341 raft_consensus.cc:515] T b46b8f828a974a6f8127ecfc403ec57e P 75fb46b29f24499b9ad90abf7891be61 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "75fb46b29f24499b9ad90abf7891be61" member_type: VOTER last_known_addr { host: "127.20.107.193" port: 33113 } }
I20260812 06:19:21.534709 21341 leader_election.cc:304] T b46b8f828a974a6f8127ecfc403ec57e P 75fb46b29f24499b9ad90abf7891be61 [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: 75fb46b29f24499b9ad90abf7891be61; no voters: 
I20260812 06:19:21.534859 21341 leader_election.cc:290] T b46b8f828a974a6f8127ecfc403ec57e P 75fb46b29f24499b9ad90abf7891be61 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:21.535012 21343 raft_consensus.cc:2804] T b46b8f828a974a6f8127ecfc403ec57e P 75fb46b29f24499b9ad90abf7891be61 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:21.535192 21327 heartbeater.cc:499] Master 127.20.107.254:44665 was elected leader, sending a full tablet report...
I20260812 06:19:21.535188 21341 ts_tablet_manager.cc:1434] T b46b8f828a974a6f8127ecfc403ec57e P 75fb46b29f24499b9ad90abf7891be61: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:19:21.535290 21343 raft_consensus.cc:697] T b46b8f828a974a6f8127ecfc403ec57e P 75fb46b29f24499b9ad90abf7891be61 [term 1 LEADER]: Becoming Leader. State: Replica: 75fb46b29f24499b9ad90abf7891be61, State: Running, Role: LEADER
I20260812 06:19:21.535429 21343 consensus_queue.cc:237] T b46b8f828a974a6f8127ecfc403ec57e P 75fb46b29f24499b9ad90abf7891be61 [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: "75fb46b29f24499b9ad90abf7891be61" member_type: VOTER last_known_addr { host: "127.20.107.193" port: 33113 } }
I20260812 06:19:21.536783 21177 catalog_manager.cc:5719] T b46b8f828a974a6f8127ecfc403ec57e P 75fb46b29f24499b9ad90abf7891be61 reported cstate change: term changed from 0 to 1, leader changed from <none> to 75fb46b29f24499b9ad90abf7891be61 (127.20.107.193). New cstate: current_term: 1 leader_uuid: "75fb46b29f24499b9ad90abf7891be61" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "75fb46b29f24499b9ad90abf7891be61" member_type: VOTER last_known_addr { host: "127.20.107.193" port: 33113 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:21.597261 20911 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.053s	user 0.018s	sys 0.004s
I20260812 06:19:21.754390 21328 maintenance_manager.cc:419] P 75fb46b29f24499b9ad90abf7891be61: Scheduling FlushMRSOp(b46b8f828a974a6f8127ecfc403ec57e): perf score=22.031503
I20260812 06:19:21.922618 21263 maintenance_manager.cc:643] P 75fb46b29f24499b9ad90abf7891be61: FlushMRSOp(b46b8f828a974a6f8127ecfc403ec57e) complete. Timing: real 0.168s	user 0.111s	sys 0.048s Metrics: {"bytes_written":12307490,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":82,"dirs.run_cpu_time_us":226,"dirs.run_wall_time_us":946,"drs_written":1,"lbm_read_time_us":76,"lbm_reads_lt_1ms":4,"lbm_write_time_us":42626,"lbm_writes_lt_1ms":857,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"update_count":1500}
I20260812 06:19:21.923302 21328 maintenance_manager.cc:419] P 75fb46b29f24499b9ad90abf7891be61: Scheduling LogGCOp(b46b8f828a974a6f8127ecfc403ec57e): free 20743831 bytes of WAL
I20260812 06:19:21.923517 21263 log_reader.cc:385] T b46b8f828a974a6f8127ecfc403ec57e: removed 2 log segments from log reader
I20260812 06:19:21.923573 21263 log.cc:1079] T b46b8f828a974a6f8127ecfc403ec57e P 75fb46b29f24499b9ad90abf7891be61: Deleting log segment in path: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515555931601-20911-0/minicluster-data/ts-0-root/wals/b46b8f828a974a6f8127ecfc403ec57e/wal-000000001 (ops 1-6)
I20260812 06:19:21.923626 21263 log.cc:1079] T b46b8f828a974a6f8127ecfc403ec57e P 75fb46b29f24499b9ad90abf7891be61: Deleting log segment in path: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515555931601-20911-0/minicluster-data/ts-0-root/wals/b46b8f828a974a6f8127ecfc403ec57e/wal-000000002 (ops 7-11)
I20260812 06:19:21.927943 21263 maintenance_manager.cc:643] P 75fb46b29f24499b9ad90abf7891be61: LogGCOp(b46b8f828a974a6f8127ecfc403ec57e) complete. Timing: real 0.004s	user 0.000s	sys 0.004s Metrics: {}
I20260812 06:19:21.928282 21328 maintenance_manager.cc:419] P 75fb46b29f24499b9ad90abf7891be61: Scheduling UndoDeltaBlockGCOp(b46b8f828a974a6f8127ecfc403ec57e): 20513814 bytes on disk
I20260812 06:19:21.928722 21263 maintenance_manager.cc:643] P 75fb46b29f24499b9ad90abf7891be61: UndoDeltaBlockGCOp(b46b8f828a974a6f8127ecfc403ec57e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4}
I20260812 06:19:21.929101 21328 maintenance_manager.cc:419] P 75fb46b29f24499b9ad90abf7891be61: Scheduling FlushDeltaMemStoresOp(b46b8f828a974a6f8127ecfc403ec57e): perf score=2.188937
I20260812 06:19:21.940431 21263 maintenance_manager.cc:643] P 75fb46b29f24499b9ad90abf7891be61: FlushDeltaMemStoresOp(b46b8f828a974a6f8127ecfc403ec57e) complete. Timing: real 0.011s	user 0.000s	sys 0.010s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3989,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:21.940991 21328 maintenance_manager.cc:419] P 75fb46b29f24499b9ad90abf7891be61: Scheduling MajorDeltaCompactionOp(b46b8f828a974a6f8127ecfc403ec57e): perf score=1.000000
I20260812 06:19:22.088224 21263 maintenance_manager.cc:643] P 75fb46b29f24499b9ad90abf7891be61: MajorDeltaCompactionOp(b46b8f828a974a6f8127ecfc403ec57e) complete. Timing: real 0.147s	user 0.105s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713271,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":636,"lbm_read_time_us":10364,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23260,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":316,"threads_started":5,"update_count":2000}
I20260812 06:19:22.088883 21328 maintenance_manager.cc:419] P 75fb46b29f24499b9ad90abf7891be61: Scheduling FlushDeltaMemStoresOp(b46b8f828a974a6f8127ecfc403ec57e): perf score=11.118625
I20260812 06:19:22.118360 21263 maintenance_manager.cc:643] P 75fb46b29f24499b9ad90abf7891be61: FlushDeltaMemStoresOp(b46b8f828a974a6f8127ecfc403ec57e) complete. Timing: real 0.029s	user 0.019s	sys 0.007s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":12977,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:22.118957 21328 maintenance_manager.cc:419] P 75fb46b29f24499b9ad90abf7891be61: Scheduling FlushDeltaMemStoresOp(b46b8f828a974a6f8127ecfc403ec57e): perf score=2.188937
I20260812 06:19:22.136922 21263 maintenance_manager.cc:643] P 75fb46b29f24499b9ad90abf7891be61: FlushDeltaMemStoresOp(b46b8f828a974a6f8127ecfc403ec57e) complete. Timing: real 0.018s	user 0.014s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5220,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:22.137549 21328 maintenance_manager.cc:419] P 75fb46b29f24499b9ad90abf7891be61: Scheduling MajorDeltaCompactionOp(b46b8f828a974a6f8127ecfc403ec57e): perf score=1.000000
I20260812 06:19:22.288995 21263 maintenance_manager.cc:643] P 75fb46b29f24499b9ad90abf7891be61: MajorDeltaCompactionOp(b46b8f828a974a6f8127ecfc403ec57e) complete. Timing: real 0.151s	user 0.097s	sys 0.043s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713263,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1045,"lbm_read_time_us":8219,"lbm_reads_lt_1ms":464,"lbm_write_time_us":21927,"lbm_writes_lt_1ms":443,"mutex_wait_us":46,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1920,"update_count":2000}
I20260812 06:19:22.289700 21328 maintenance_manager.cc:419] P 75fb46b29f24499b9ad90abf7891be61: Scheduling FlushDeltaMemStoresOp(b46b8f828a974a6f8127ecfc403ec57e): perf score=14.095187
I20260812 06:19:22.337889 21263 maintenance_manager.cc:643] P 75fb46b29f24499b9ad90abf7891be61: FlushDeltaMemStoresOp(b46b8f828a974a6f8127ecfc403ec57e) complete. Timing: real 0.048s	user 0.024s	sys 0.015s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":18952,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:22.338352 21328 maintenance_manager.cc:419] P 75fb46b29f24499b9ad90abf7891be61: Scheduling FlushDeltaMemStoresOp(b46b8f828a974a6f8127ecfc403ec57e): perf score=2.188937
I20260812 06:19:22.349596 21263 maintenance_manager.cc:643] P 75fb46b29f24499b9ad90abf7891be61: FlushDeltaMemStoresOp(b46b8f828a974a6f8127ecfc403ec57e) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4104,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:22.350129 21328 maintenance_manager.cc:419] P 75fb46b29f24499b9ad90abf7891be61: Scheduling MajorDeltaCompactionOp(b46b8f828a974a6f8127ecfc403ec57e): perf score=1.000000
I20260812 06:19:22.498245 21263 maintenance_manager.cc:643] P 75fb46b29f24499b9ad90abf7891be61: MajorDeltaCompactionOp(b46b8f828a974a6f8127ecfc403ec57e) complete. Timing: real 0.148s	user 0.113s	sys 0.032s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":252,"lbm_read_time_us":11294,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29539,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9600,"update_count":2500}
I20260812 06:19:22.499038 21328 maintenance_manager.cc:419] P 75fb46b29f24499b9ad90abf7891be61: Scheduling FlushDeltaMemStoresOp(b46b8f828a974a6f8127ecfc403ec57e): perf score=11.118625
I20260812 06:19:22.530452 21263 maintenance_manager.cc:643] P 75fb46b29f24499b9ad90abf7891be61: FlushDeltaMemStoresOp(b46b8f828a974a6f8127ecfc403ec57e) complete. Timing: real 0.031s	user 0.018s	sys 0.009s Metrics: {"bytes_written":12512610,"delete_count":0,"lbm_write_time_us":13151,"lbm_writes_lt_1ms":308,"reinsert_count":0,"update_count":1525}
I20260812 06:19:22.530961 21328 maintenance_manager.cc:419] P 75fb46b29f24499b9ad90abf7891be61: Scheduling FlushDeltaMemStoresOp(b46b8f828a974a6f8127ecfc403ec57e): perf score=2.188937
I20260812 06:19:22.542505 21263 maintenance_manager.cc:643] P 75fb46b29f24499b9ad90abf7891be61: FlushDeltaMemStoresOp(b46b8f828a974a6f8127ecfc403ec57e) complete. Timing: real 0.011s	user 0.008s	sys 0.001s Metrics: {"bytes_written":3897534,"delete_count":0,"lbm_write_time_us":3885,"lbm_writes_lt_1ms":98,"reinsert_count":0,"update_count":475}
I20260812 06:19:22.542981 21328 maintenance_manager.cc:419] P 75fb46b29f24499b9ad90abf7891be61: Scheduling MajorDeltaCompactionOp(b46b8f828a974a6f8127ecfc403ec57e): perf score=1.000000
I20260812 06:19:22.663431 21263 maintenance_manager.cc:643] P 75fb46b29f24499b9ad90abf7891be61: MajorDeltaCompactionOp(b46b8f828a974a6f8127ecfc403ec57e) complete. Timing: real 0.120s	user 0.089s	sys 0.031s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713267,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":582,"lbm_read_time_us":8692,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23353,"lbm_writes_lt_1ms":443,"mutex_wait_us":51,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6272,"update_count":2000}
I20260812 06:19:22.665210 21328 maintenance_manager.cc:419] P 75fb46b29f24499b9ad90abf7891be61: Scheduling FlushDeltaMemStoresOp(b46b8f828a974a6f8127ecfc403ec57e): perf score=10.126437
I20260812 06:19:22.708520 21263 maintenance_manager.cc:643] P 75fb46b29f24499b9ad90abf7891be61: FlushDeltaMemStoresOp(b46b8f828a974a6f8127ecfc403ec57e) complete. Timing: real 0.043s	user 0.014s	sys 0.028s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":14377,"lbm_writes_lt_1ms":303,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":1500}
I20260812 06:19:22.709048 21328 maintenance_manager.cc:419] P 75fb46b29f24499b9ad90abf7891be61: Scheduling FlushDeltaMemStoresOp(b46b8f828a974a6f8127ecfc403ec57e): perf score=2.188937
I20260812 06:19:22.719805 21263 maintenance_manager.cc:643] P 75fb46b29f24499b9ad90abf7891be61: FlushDeltaMemStoresOp(b46b8f828a974a6f8127ecfc403ec57e) complete. Timing: real 0.011s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4314,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:22.720227 21328 maintenance_manager.cc:419] P 75fb46b29f24499b9ad90abf7891be61: Scheduling MajorDeltaCompactionOp(b46b8f828a974a6f8127ecfc403ec57e): perf score=1.000000
I20260812 06:19:22.863680 21263 maintenance_manager.cc:643] P 75fb46b29f24499b9ad90abf7891be61: MajorDeltaCompactionOp(b46b8f828a974a6f8127ecfc403ec57e) complete. Timing: real 0.143s	user 0.085s	sys 0.058s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713270,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":335,"lbm_read_time_us":11060,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22874,"lbm_writes_lt_1ms":443,"mutex_wait_us":57,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4096,"update_count":2000}
I20260812 06:19:22.864327 21328 maintenance_manager.cc:419] P 75fb46b29f24499b9ad90abf7891be61: Scheduling FlushDeltaMemStoresOp(b46b8f828a974a6f8127ecfc403ec57e): perf score=10.126437
I20260812 06:19:22.905292 21263 maintenance_manager.cc:643] P 75fb46b29f24499b9ad90abf7891be61: FlushDeltaMemStoresOp(b46b8f828a974a6f8127ecfc403ec57e) complete. Timing: real 0.041s	user 0.015s	sys 0.020s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":16346,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:22.905795 21328 maintenance_manager.cc:419] P 75fb46b29f24499b9ad90abf7891be61: Scheduling FlushDeltaMemStoresOp(b46b8f828a974a6f8127ecfc403ec57e): perf score=2.188937
I20260812 06:19:22.916368 21263 maintenance_manager.cc:643] P 75fb46b29f24499b9ad90abf7891be61: FlushDeltaMemStoresOp(b46b8f828a974a6f8127ecfc403ec57e) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4090,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:22.917084 21328 maintenance_manager.cc:419] P 75fb46b29f24499b9ad90abf7891be61: Scheduling MajorDeltaCompactionOp(b46b8f828a974a6f8127ecfc403ec57e): perf score=1.000000
I20260812 06:19:23.050119 21263 maintenance_manager.cc:643] P 75fb46b29f24499b9ad90abf7891be61: MajorDeltaCompactionOp(b46b8f828a974a6f8127ecfc403ec57e) complete. Timing: real 0.133s	user 0.097s	sys 0.036s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20713275,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":582,"lbm_read_time_us":7510,"lbm_reads_lt_1ms":472,"lbm_write_time_us":28219,"lbm_writes_lt_1ms":443,"mutex_wait_us":244,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":16768,"update_count":2000}
I20260812 06:19:23.050725 21328 maintenance_manager.cc:419] P 75fb46b29f24499b9ad90abf7891be61: Scheduling FlushDeltaMemStoresOp(b46b8f828a974a6f8127ecfc403ec57e): perf score=10.126437
I20260812 06:19:23.095695 21263 maintenance_manager.cc:643] P 75fb46b29f24499b9ad90abf7891be61: FlushDeltaMemStoresOp(b46b8f828a974a6f8127ecfc403ec57e) complete. Timing: real 0.045s	user 0.017s	sys 0.015s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":14461,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:23.096254 21328 maintenance_manager.cc:419] P 75fb46b29f24499b9ad90abf7891be61: Scheduling FlushDeltaMemStoresOp(b46b8f828a974a6f8127ecfc403ec57e): perf score=2.188937
I20260812 06:19:23.111565 21263 maintenance_manager.cc:643] P 75fb46b29f24499b9ad90abf7891be61: FlushDeltaMemStoresOp(b46b8f828a974a6f8127ecfc403ec57e) complete. Timing: real 0.015s	user 0.007s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5832,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:23.112128 21328 maintenance_manager.cc:419] P 75fb46b29f24499b9ad90abf7891be61: Scheduling FlushMRSOp(b46b8f828a974a6f8127ecfc403ec57e): perf score=1.000000
I20260812 06:19:23.141881 21263 maintenance_manager.cc:643] P 75fb46b29f24499b9ad90abf7891be61: FlushMRSOp(b46b8f828a974a6f8127ecfc403ec57e) complete. Timing: real 0.030s	user 0.025s	sys 0.000s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":68,"dirs.run_cpu_time_us":267,"dirs.run_wall_time_us":1442,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1418,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:23.142529 21328 maintenance_manager.cc:419] P 75fb46b29f24499b9ad90abf7891be61: Scheduling LogGCOp(b46b8f828a974a6f8127ecfc403ec57e): free 120553429 bytes of WAL
I20260812 06:19:23.142789 21263 log_reader.cc:385] T b46b8f828a974a6f8127ecfc403ec57e: removed 12 log segments from log reader
I20260812 06:19:23.142851 21263 log.cc:1079] T b46b8f828a974a6f8127ecfc403ec57e P 75fb46b29f24499b9ad90abf7891be61: Deleting log segment in path: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515555931601-20911-0/minicluster-data/ts-0-root/wals/b46b8f828a974a6f8127ecfc403ec57e/wal-000000003 (ops 12-16)
I20260812 06:19:23.142892 21263 log.cc:1079] T b46b8f828a974a6f8127ecfc403ec57e P 75fb46b29f24499b9ad90abf7891be61: Deleting log segment in path: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515555931601-20911-0/minicluster-data/ts-0-root/wals/b46b8f828a974a6f8127ecfc403ec57e/wal-000000004 (ops 17-21)
I20260812 06:19:23.142925 21263 log.cc:1079] T b46b8f828a974a6f8127ecfc403ec57e P 75fb46b29f24499b9ad90abf7891be61: Deleting log segment in path: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515555931601-20911-0/minicluster-data/ts-0-root/wals/b46b8f828a974a6f8127ecfc403ec57e/wal-000000005 (ops 22-26)
I20260812 06:19:23.142946 21263 log.cc:1079] T b46b8f828a974a6f8127ecfc403ec57e P 75fb46b29f24499b9ad90abf7891be61: Deleting log segment in path: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515555931601-20911-0/minicluster-data/ts-0-root/wals/b46b8f828a974a6f8127ecfc403ec57e/wal-000000006 (ops 27-30)
I20260812 06:19:23.142969 21263 log.cc:1079] T b46b8f828a974a6f8127ecfc403ec57e P 75fb46b29f24499b9ad90abf7891be61: Deleting log segment in path: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515555931601-20911-0/minicluster-data/ts-0-root/wals/b46b8f828a974a6f8127ecfc403ec57e/wal-000000007 (ops 31-35)
I20260812 06:19:23.143002 21263 log.cc:1079] T b46b8f828a974a6f8127ecfc403ec57e P 75fb46b29f24499b9ad90abf7891be61: Deleting log segment in path: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515555931601-20911-0/minicluster-data/ts-0-root/wals/b46b8f828a974a6f8127ecfc403ec57e/wal-000000008 (ops 36-40)
I20260812 06:19:23.143029 21263 log.cc:1079] T b46b8f828a974a6f8127ecfc403ec57e P 75fb46b29f24499b9ad90abf7891be61: Deleting log segment in path: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515555931601-20911-0/minicluster-data/ts-0-root/wals/b46b8f828a974a6f8127ecfc403ec57e/wal-000000009 (ops 41-45)
I20260812 06:19:23.143061 21263 log.cc:1079] T b46b8f828a974a6f8127ecfc403ec57e P 75fb46b29f24499b9ad90abf7891be61: Deleting log segment in path: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515555931601-20911-0/minicluster-data/ts-0-root/wals/b46b8f828a974a6f8127ecfc403ec57e/wal-000000010 (ops 46-50)
I20260812 06:19:23.143165 21263 log.cc:1079] T b46b8f828a974a6f8127ecfc403ec57e P 75fb46b29f24499b9ad90abf7891be61: Deleting log segment in path: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515555931601-20911-0/minicluster-data/ts-0-root/wals/b46b8f828a974a6f8127ecfc403ec57e/wal-000000011 (ops 51-55)
I20260812 06:19:23.143205 21263 log.cc:1079] T b46b8f828a974a6f8127ecfc403ec57e P 75fb46b29f24499b9ad90abf7891be61: Deleting log segment in path: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515555931601-20911-0/minicluster-data/ts-0-root/wals/b46b8f828a974a6f8127ecfc403ec57e/wal-000000012 (ops 56-60)
I20260812 06:19:23.143232 21263 log.cc:1079] T b46b8f828a974a6f8127ecfc403ec57e P 75fb46b29f24499b9ad90abf7891be61: Deleting log segment in path: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515555931601-20911-0/minicluster-data/ts-0-root/wals/b46b8f828a974a6f8127ecfc403ec57e/wal-000000013 (ops 61-64)
I20260812 06:19:23.143263 21263 log.cc:1079] T b46b8f828a974a6f8127ecfc403ec57e P 75fb46b29f24499b9ad90abf7891be61: Deleting log segment in path: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515555931601-20911-0/minicluster-data/ts-0-root/wals/b46b8f828a974a6f8127ecfc403ec57e/wal-000000014 (ops 65-69)
I20260812 06:19:23.172185 21263 maintenance_manager.cc:643] P 75fb46b29f24499b9ad90abf7891be61: LogGCOp(b46b8f828a974a6f8127ecfc403ec57e) complete. Timing: real 0.029s	user 0.002s	sys 0.027s Metrics: {}
I20260812 06:19:23.172633 21328 maintenance_manager.cc:419] P 75fb46b29f24499b9ad90abf7891be61: Scheduling UndoDeltaBlockGCOp(b46b8f828a974a6f8127ecfc403ec57e): 462 bytes on disk
I20260812 06:19:23.173162 21263 maintenance_manager.cc:643] P 75fb46b29f24499b9ad90abf7891be61: UndoDeltaBlockGCOp(b46b8f828a974a6f8127ecfc403ec57e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":92,"lbm_reads_lt_1ms":4}
I20260812 06:19:23.173703 21328 maintenance_manager.cc:419] P 75fb46b29f24499b9ad90abf7891be61: Scheduling FlushDeltaMemStoresOp(b46b8f828a974a6f8127ecfc403ec57e): perf score=2.188937
I20260812 06:19:23.197458 21263 maintenance_manager.cc:643] P 75fb46b29f24499b9ad90abf7891be61: FlushDeltaMemStoresOp(b46b8f828a974a6f8127ecfc403ec57e) complete. Timing: real 0.024s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5456,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:23.197934 21328 maintenance_manager.cc:419] P 75fb46b29f24499b9ad90abf7891be61: Scheduling FlushDeltaMemStoresOp(b46b8f828a974a6f8127ecfc403ec57e): perf score=2.188937
I20260812 06:19:23.212055 21263 maintenance_manager.cc:643] P 75fb46b29f24499b9ad90abf7891be61: FlushDeltaMemStoresOp(b46b8f828a974a6f8127ecfc403ec57e) complete. Timing: real 0.014s	user 0.012s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5534,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:23.212517 21328 maintenance_manager.cc:419] P 75fb46b29f24499b9ad90abf7891be61: Scheduling MajorDeltaCompactionOp(b46b8f828a974a6f8127ecfc403ec57e): perf score=1.000000
I20260812 06:19:23.393589 21263 maintenance_manager.cc:643] P 75fb46b29f24499b9ad90abf7891be61: MajorDeltaCompactionOp(b46b8f828a974a6f8127ecfc403ec57e) complete. Timing: real 0.181s	user 0.138s	sys 0.037s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28918332,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":218,"lbm_read_time_us":11619,"lbm_reads_lt_1ms":674,"lbm_write_time_us":36205,"lbm_writes_lt_1ms":643,"mutex_wait_us":261,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":17536,"thread_start_us":76,"threads_started":1,"update_count":3000}
I20260812 06:19:23.394276 21328 maintenance_manager.cc:419] P 75fb46b29f24499b9ad90abf7891be61: Scheduling FlushDeltaMemStoresOp(b46b8f828a974a6f8127ecfc403ec57e): perf score=14.095187
I20260812 06:19:23.448764 21263 maintenance_manager.cc:643] P 75fb46b29f24499b9ad90abf7891be61: FlushDeltaMemStoresOp(b46b8f828a974a6f8127ecfc403ec57e) complete. Timing: real 0.054s	user 0.028s	sys 0.025s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24113,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:23.449246 21328 maintenance_manager.cc:419] P 75fb46b29f24499b9ad90abf7891be61: Scheduling FlushDeltaMemStoresOp(b46b8f828a974a6f8127ecfc403ec57e): perf score=2.188937
I20260812 06:19:23.461372 21263 maintenance_manager.cc:643] P 75fb46b29f24499b9ad90abf7891be61: FlushDeltaMemStoresOp(b46b8f828a974a6f8127ecfc403ec57e) complete. Timing: real 0.012s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4440,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:23.461917 21328 maintenance_manager.cc:419] P 75fb46b29f24499b9ad90abf7891be61: Scheduling MajorDeltaCompactionOp(b46b8f828a974a6f8127ecfc403ec57e): perf score=1.000000
I20260812 06:19:23.629520 21263 maintenance_manager.cc:643] P 75fb46b29f24499b9ad90abf7891be61: MajorDeltaCompactionOp(b46b8f828a974a6f8127ecfc403ec57e) complete. Timing: real 0.167s	user 0.122s	sys 0.033s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1137,"lbm_read_time_us":11751,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29875,"lbm_writes_lt_1ms":543,"mutex_wait_us":314,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":15360,"update_count":2500}
I20260812 06:19:23.630172 21328 maintenance_manager.cc:419] P 75fb46b29f24499b9ad90abf7891be61: Scheduling FlushDeltaMemStoresOp(b46b8f828a974a6f8127ecfc403ec57e): perf score=14.095187
I20260812 06:19:23.680613 21263 maintenance_manager.cc:643] P 75fb46b29f24499b9ad90abf7891be61: FlushDeltaMemStoresOp(b46b8f828a974a6f8127ecfc403ec57e) complete. Timing: real 0.050s	user 0.021s	sys 0.019s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":18268,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:23.681078 21328 maintenance_manager.cc:419] P 75fb46b29f24499b9ad90abf7891be61: Scheduling FlushDeltaMemStoresOp(b46b8f828a974a6f8127ecfc403ec57e): perf score=2.188937
I20260812 06:19:23.692619 21263 maintenance_manager.cc:643] P 75fb46b29f24499b9ad90abf7891be61: FlushDeltaMemStoresOp(b46b8f828a974a6f8127ecfc403ec57e) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4408,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:23.693092 21328 maintenance_manager.cc:419] P 75fb46b29f24499b9ad90abf7891be61: Scheduling MajorDeltaCompactionOp(b46b8f828a974a6f8127ecfc403ec57e): perf score=1.000000
I20260812 06:19:23.870885 21263 maintenance_manager.cc:643] P 75fb46b29f24499b9ad90abf7891be61: MajorDeltaCompactionOp(b46b8f828a974a6f8127ecfc403ec57e) complete. Timing: real 0.178s	user 0.121s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":531,"lbm_read_time_us":10209,"lbm_reads_lt_1ms":572,"lbm_write_time_us":34989,"lbm_writes_lt_1ms":543,"mutex_wait_us":119,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":15616,"update_count":2500}
I20260812 06:19:23.871515 21328 maintenance_manager.cc:419] P 75fb46b29f24499b9ad90abf7891be61: Scheduling FlushDeltaMemStoresOp(b46b8f828a974a6f8127ecfc403ec57e): perf score=14.095187
I20260812 06:19:23.916725 21263 maintenance_manager.cc:643] P 75fb46b29f24499b9ad90abf7891be61: FlushDeltaMemStoresOp(b46b8f828a974a6f8127ecfc403ec57e) complete. Timing: real 0.045s	user 0.024s	sys 0.015s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":18521,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:23.917285 21328 maintenance_manager.cc:419] P 75fb46b29f24499b9ad90abf7891be61: Scheduling MajorDeltaCompactionOp(b46b8f828a974a6f8127ecfc403ec57e): perf score=1.000000
I20260812 06:19:24.069959 21263 maintenance_manager.cc:643] P 75fb46b29f24499b9ad90abf7891be61: MajorDeltaCompactionOp(b46b8f828a974a6f8127ecfc403ec57e) complete. Timing: real 0.152s	user 0.097s	sys 0.048s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713155,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":345,"lbm_read_time_us":10352,"lbm_reads_lt_1ms":463,"lbm_write_time_us":25006,"lbm_writes_lt_1ms":443,"mutex_wait_us":45,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2176,"update_count":2000}
I20260812 06:19:24.070554 21328 maintenance_manager.cc:419] P 75fb46b29f24499b9ad90abf7891be61: Scheduling FlushDeltaMemStoresOp(b46b8f828a974a6f8127ecfc403ec57e): perf score=14.095187
I20260812 06:19:24.134589 21263 maintenance_manager.cc:643] P 75fb46b29f24499b9ad90abf7891be61: FlushDeltaMemStoresOp(b46b8f828a974a6f8127ecfc403ec57e) complete. Timing: real 0.064s	user 0.029s	sys 0.031s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":25507,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"spinlock_wait_cycles":2816,"update_count":2000}
I20260812 06:19:24.135206 21328 maintenance_manager.cc:419] P 75fb46b29f24499b9ad90abf7891be61: Scheduling FlushDeltaMemStoresOp(b46b8f828a974a6f8127ecfc403ec57e): perf score=2.188937
I20260812 06:19:24.145789 21263 maintenance_manager.cc:643] P 75fb46b29f24499b9ad90abf7891be61: FlushDeltaMemStoresOp(b46b8f828a974a6f8127ecfc403ec57e) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4210,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:24.146287 21328 maintenance_manager.cc:419] P 75fb46b29f24499b9ad90abf7891be61: Scheduling MajorDeltaCompactionOp(b46b8f828a974a6f8127ecfc403ec57e): perf score=1.000000
I20260812 06:19:24.330024 21263 maintenance_manager.cc:643] P 75fb46b29f24499b9ad90abf7891be61: MajorDeltaCompactionOp(b46b8f828a974a6f8127ecfc403ec57e) complete. Timing: real 0.184s	user 0.124s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":242,"lbm_read_time_us":12431,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27669,"lbm_writes_lt_1ms":543,"mutex_wait_us":2,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2304,"update_count":2500}
I20260812 06:19:24.330578 21328 maintenance_manager.cc:419] P 75fb46b29f24499b9ad90abf7891be61: Scheduling FlushDeltaMemStoresOp(b46b8f828a974a6f8127ecfc403ec57e): perf score=14.095187
I20260812 06:19:24.394191 21263 maintenance_manager.cc:643] P 75fb46b29f24499b9ad90abf7891be61: FlushDeltaMemStoresOp(b46b8f828a974a6f8127ecfc403ec57e) complete. Timing: real 0.063s	user 0.013s	sys 0.043s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21932,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:24.394752 21328 maintenance_manager.cc:419] P 75fb46b29f24499b9ad90abf7891be61: Scheduling FlushDeltaMemStoresOp(b46b8f828a974a6f8127ecfc403ec57e): perf score=2.188937
I20260812 06:19:24.411418 21263 maintenance_manager.cc:643] P 75fb46b29f24499b9ad90abf7891be61: FlushDeltaMemStoresOp(b46b8f828a974a6f8127ecfc403ec57e) complete. Timing: real 0.016s	user 0.016s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6228,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:24.412050 21328 maintenance_manager.cc:419] P 75fb46b29f24499b9ad90abf7891be61: Scheduling MajorDeltaCompactionOp(b46b8f828a974a6f8127ecfc403ec57e): perf score=1.000000
I20260812 06:19:24.580222 21263 maintenance_manager.cc:643] P 75fb46b29f24499b9ad90abf7891be61: MajorDeltaCompactionOp(b46b8f828a974a6f8127ecfc403ec57e) complete. Timing: real 0.168s	user 0.119s	sys 0.047s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":198,"lbm_read_time_us":12359,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28793,"lbm_writes_lt_1ms":543,"mutex_wait_us":2,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:19:24.580822 21328 maintenance_manager.cc:419] P 75fb46b29f24499b9ad90abf7891be61: Scheduling FlushDeltaMemStoresOp(b46b8f828a974a6f8127ecfc403ec57e): perf score=11.118625
I20260812 06:19:24.624106 21263 maintenance_manager.cc:643] P 75fb46b29f24499b9ad90abf7891be61: FlushDeltaMemStoresOp(b46b8f828a974a6f8127ecfc403ec57e) complete. Timing: real 0.043s	user 0.019s	sys 0.023s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":18916,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:19:24.624897 21328 maintenance_manager.cc:419] P 75fb46b29f24499b9ad90abf7891be61: Scheduling FlushDeltaMemStoresOp(b46b8f828a974a6f8127ecfc403ec57e): perf score=2.188937
I20260812 06:19:24.644233 21263 maintenance_manager.cc:643] P 75fb46b29f24499b9ad90abf7891be61: FlushDeltaMemStoresOp(b46b8f828a974a6f8127ecfc403ec57e) complete. Timing: real 0.019s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4886,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:24.644706 21328 maintenance_manager.cc:419] P 75fb46b29f24499b9ad90abf7891be61: Scheduling FlushDeltaMemStoresOp(b46b8f828a974a6f8127ecfc403ec57e): perf score=2.188937
I20260812 06:19:24.664565 21263 maintenance_manager.cc:643] P 75fb46b29f24499b9ad90abf7891be61: FlushDeltaMemStoresOp(b46b8f828a974a6f8127ecfc403ec57e) complete. Timing: real 0.020s	user 0.001s	sys 0.017s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3758,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:24.665037 21328 maintenance_manager.cc:419] P 75fb46b29f24499b9ad90abf7891be61: Scheduling FlushMRSOp(b46b8f828a974a6f8127ecfc403ec57e): perf score=1.000000
I20260812 06:19:24.703011 21263 maintenance_manager.cc:643] P 75fb46b29f24499b9ad90abf7891be61: FlushMRSOp(b46b8f828a974a6f8127ecfc403ec57e) complete. Timing: real 0.038s	user 0.031s	sys 0.000s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":87,"dirs.run_cpu_time_us":271,"dirs.run_wall_time_us":1681,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1499,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:24.703756 21328 maintenance_manager.cc:419] P 75fb46b29f24499b9ad90abf7891be61: Scheduling LogGCOp(b46b8f828a974a6f8127ecfc403ec57e): free 128867458 bytes of WAL
I20260812 06:19:24.703986 21263 log_reader.cc:385] T b46b8f828a974a6f8127ecfc403ec57e: removed 13 log segments from log reader
I20260812 06:19:24.704033 21263 log.cc:1079] T b46b8f828a974a6f8127ecfc403ec57e P 75fb46b29f24499b9ad90abf7891be61: Deleting log segment in path: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515555931601-20911-0/minicluster-data/ts-0-root/wals/b46b8f828a974a6f8127ecfc403ec57e/wal-000000015 (ops 70-74)
I20260812 06:19:24.704063 21263 log.cc:1079] T b46b8f828a974a6f8127ecfc403ec57e P 75fb46b29f24499b9ad90abf7891be61: Deleting log segment in path: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515555931601-20911-0/minicluster-data/ts-0-root/wals/b46b8f828a974a6f8127ecfc403ec57e/wal-000000016 (ops 75-78)
I20260812 06:19:24.704125 21263 log.cc:1079] T b46b8f828a974a6f8127ecfc403ec57e P 75fb46b29f24499b9ad90abf7891be61: Deleting log segment in path: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515555931601-20911-0/minicluster-data/ts-0-root/wals/b46b8f828a974a6f8127ecfc403ec57e/wal-000000017 (ops 79-83)
I20260812 06:19:24.704166 21263 log.cc:1079] T b46b8f828a974a6f8127ecfc403ec57e P 75fb46b29f24499b9ad90abf7891be61: Deleting log segment in path: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515555931601-20911-0/minicluster-data/ts-0-root/wals/b46b8f828a974a6f8127ecfc403ec57e/wal-000000018 (ops 84-88)
I20260812 06:19:24.704208 21263 log.cc:1079] T b46b8f828a974a6f8127ecfc403ec57e P 75fb46b29f24499b9ad90abf7891be61: Deleting log segment in path: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515555931601-20911-0/minicluster-data/ts-0-root/wals/b46b8f828a974a6f8127ecfc403ec57e/wal-000000019 (ops 89-93)
I20260812 06:19:24.704247 21263 log.cc:1079] T b46b8f828a974a6f8127ecfc403ec57e P 75fb46b29f24499b9ad90abf7891be61: Deleting log segment in path: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515555931601-20911-0/minicluster-data/ts-0-root/wals/b46b8f828a974a6f8127ecfc403ec57e/wal-000000020 (ops 94-98)
I20260812 06:19:24.704288 21263 log.cc:1079] T b46b8f828a974a6f8127ecfc403ec57e P 75fb46b29f24499b9ad90abf7891be61: Deleting log segment in path: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515555931601-20911-0/minicluster-data/ts-0-root/wals/b46b8f828a974a6f8127ecfc403ec57e/wal-000000021 (ops 99-103)
I20260812 06:19:24.704326 21263 log.cc:1079] T b46b8f828a974a6f8127ecfc403ec57e P 75fb46b29f24499b9ad90abf7891be61: Deleting log segment in path: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515555931601-20911-0/minicluster-data/ts-0-root/wals/b46b8f828a974a6f8127ecfc403ec57e/wal-000000022 (ops 104-108)
I20260812 06:19:24.704365 21263 log.cc:1079] T b46b8f828a974a6f8127ecfc403ec57e P 75fb46b29f24499b9ad90abf7891be61: Deleting log segment in path: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515555931601-20911-0/minicluster-data/ts-0-root/wals/b46b8f828a974a6f8127ecfc403ec57e/wal-000000023 (ops 109-112)
I20260812 06:19:24.704404 21263 log.cc:1079] T b46b8f828a974a6f8127ecfc403ec57e P 75fb46b29f24499b9ad90abf7891be61: Deleting log segment in path: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515555931601-20911-0/minicluster-data/ts-0-root/wals/b46b8f828a974a6f8127ecfc403ec57e/wal-000000024 (ops 113-117)
I20260812 06:19:24.704447 21263 log.cc:1079] T b46b8f828a974a6f8127ecfc403ec57e P 75fb46b29f24499b9ad90abf7891be61: Deleting log segment in path: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515555931601-20911-0/minicluster-data/ts-0-root/wals/b46b8f828a974a6f8127ecfc403ec57e/wal-000000025 (ops 118-122)
I20260812 06:19:24.704483 21263 log.cc:1079] T b46b8f828a974a6f8127ecfc403ec57e P 75fb46b29f24499b9ad90abf7891be61: Deleting log segment in path: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515555931601-20911-0/minicluster-data/ts-0-root/wals/b46b8f828a974a6f8127ecfc403ec57e/wal-000000026 (ops 123-126)
I20260812 06:19:24.704521 21263 log.cc:1079] T b46b8f828a974a6f8127ecfc403ec57e P 75fb46b29f24499b9ad90abf7891be61: Deleting log segment in path: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515555931601-20911-0/minicluster-data/ts-0-root/wals/b46b8f828a974a6f8127ecfc403ec57e/wal-000000027 (ops 127-131)
I20260812 06:19:24.730866 21263 maintenance_manager.cc:643] P 75fb46b29f24499b9ad90abf7891be61: LogGCOp(b46b8f828a974a6f8127ecfc403ec57e) complete. Timing: real 0.027s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:19:24.731287 21328 maintenance_manager.cc:419] P 75fb46b29f24499b9ad90abf7891be61: Scheduling UndoDeltaBlockGCOp(b46b8f828a974a6f8127ecfc403ec57e): 482 bytes on disk
I20260812 06:19:24.731703 21263 maintenance_manager.cc:643] P 75fb46b29f24499b9ad90abf7891be61: UndoDeltaBlockGCOp(b46b8f828a974a6f8127ecfc403ec57e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4}
I20260812 06:19:24.732197 21328 maintenance_manager.cc:419] P 75fb46b29f24499b9ad90abf7891be61: Scheduling FlushDeltaMemStoresOp(b46b8f828a974a6f8127ecfc403ec57e): perf score=3.181125
I20260812 06:19:24.755885 21263 maintenance_manager.cc:643] P 75fb46b29f24499b9ad90abf7891be61: FlushDeltaMemStoresOp(b46b8f828a974a6f8127ecfc403ec57e) complete. Timing: real 0.024s	user 0.013s	sys 0.004s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":6763,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:24.756403 21328 maintenance_manager.cc:419] P 75fb46b29f24499b9ad90abf7891be61: Scheduling FlushDeltaMemStoresOp(b46b8f828a974a6f8127ecfc403ec57e): perf score=2.188937
I20260812 06:19:24.765746 21263 maintenance_manager.cc:643] P 75fb46b29f24499b9ad90abf7891be61: FlushDeltaMemStoresOp(b46b8f828a974a6f8127ecfc403ec57e) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3528,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:24.766358 21328 maintenance_manager.cc:419] P 75fb46b29f24499b9ad90abf7891be61: Scheduling MajorDeltaCompactionOp(b46b8f828a974a6f8127ecfc403ec57e): perf score=1.000000
I20260812 06:19:24.991410 21263 maintenance_manager.cc:643] P 75fb46b29f24499b9ad90abf7891be61: MajorDeltaCompactionOp(b46b8f828a974a6f8127ecfc403ec57e) complete. Timing: real 0.225s	user 0.136s	sys 0.088s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":33020844,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":534,"lbm_read_time_us":14628,"lbm_reads_lt_1ms":775,"lbm_write_time_us":37886,"lbm_writes_lt_1ms":743,"mutex_wait_us":28,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":13824,"thread_start_us":82,"threads_started":1,"update_count":3500}
I20260812 06:19:24.992172 21328 maintenance_manager.cc:419] P 75fb46b29f24499b9ad90abf7891be61: Scheduling FlushDeltaMemStoresOp(b46b8f828a974a6f8127ecfc403ec57e): perf score=15.087375
I20260812 06:19:25.031792 21263 maintenance_manager.cc:643] P 75fb46b29f24499b9ad90abf7891be61: FlushDeltaMemStoresOp(b46b8f828a974a6f8127ecfc403ec57e) complete. Timing: real 0.039s	user 0.027s	sys 0.012s Metrics: {"bytes_written":16820145,"delete_count":0,"lbm_write_time_us":17898,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:19:25.032544 21328 maintenance_manager.cc:419] P 75fb46b29f24499b9ad90abf7891be61: Scheduling FlushDeltaMemStoresOp(b46b8f828a974a6f8127ecfc403ec57e): perf score=2.188937
I20260812 06:19:25.044209 21263 maintenance_manager.cc:643] P 75fb46b29f24499b9ad90abf7891be61: FlushDeltaMemStoresOp(b46b8f828a974a6f8127ecfc403ec57e) complete. Timing: real 0.011s	user 0.001s	sys 0.009s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4383,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:25.044788 21328 maintenance_manager.cc:419] P 75fb46b29f24499b9ad90abf7891be61: Scheduling MajorDeltaCompactionOp(b46b8f828a974a6f8127ecfc403ec57e): perf score=1.000000
I20260812 06:19:25.219786 21263 maintenance_manager.cc:643] P 75fb46b29f24499b9ad90abf7891be61: MajorDeltaCompactionOp(b46b8f828a974a6f8127ecfc403ec57e) complete. Timing: real 0.175s	user 0.129s	sys 0.046s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815673,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":193,"lbm_read_time_us":12978,"lbm_reads_lt_1ms":564,"lbm_write_time_us":29649,"lbm_writes_lt_1ms":543,"mutex_wait_us":2,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":25472,"update_count":2500}
I20260812 06:19:25.220456 21328 maintenance_manager.cc:419] P 75fb46b29f24499b9ad90abf7891be61: Scheduling FlushDeltaMemStoresOp(b46b8f828a974a6f8127ecfc403ec57e): perf score=14.095187
I20260812 06:19:25.275484 21263 maintenance_manager.cc:643] P 75fb46b29f24499b9ad90abf7891be61: FlushDeltaMemStoresOp(b46b8f828a974a6f8127ecfc403ec57e) complete. Timing: real 0.055s	user 0.031s	sys 0.023s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20580,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:25.275992 21328 maintenance_manager.cc:419] P 75fb46b29f24499b9ad90abf7891be61: Scheduling FlushDeltaMemStoresOp(b46b8f828a974a6f8127ecfc403ec57e): perf score=2.188937
I20260812 06:19:25.287478 21263 maintenance_manager.cc:643] P 75fb46b29f24499b9ad90abf7891be61: FlushDeltaMemStoresOp(b46b8f828a974a6f8127ecfc403ec57e) complete. Timing: real 0.011s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4113,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:25.287899 21328 maintenance_manager.cc:419] P 75fb46b29f24499b9ad90abf7891be61: Scheduling MajorDeltaCompactionOp(b46b8f828a974a6f8127ecfc403ec57e): perf score=1.000000
I20260812 06:19:25.454233 21263 maintenance_manager.cc:643] P 75fb46b29f24499b9ad90abf7891be61: MajorDeltaCompactionOp(b46b8f828a974a6f8127ecfc403ec57e) complete. Timing: real 0.166s	user 0.107s	sys 0.053s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":262,"lbm_read_time_us":11695,"lbm_reads_lt_1ms":572,"lbm_write_time_us":25964,"lbm_writes_lt_1ms":543,"mutex_wait_us":23,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2500}
I20260812 06:19:25.454792 21328 maintenance_manager.cc:419] P 75fb46b29f24499b9ad90abf7891be61: Scheduling FlushDeltaMemStoresOp(b46b8f828a974a6f8127ecfc403ec57e): perf score=14.095187
I20260812 06:19:25.515899 21263 maintenance_manager.cc:643] P 75fb46b29f24499b9ad90abf7891be61: FlushDeltaMemStoresOp(b46b8f828a974a6f8127ecfc403ec57e) complete. Timing: real 0.061s	user 0.033s	sys 0.015s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":17737,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:25.516471 21328 maintenance_manager.cc:419] P 75fb46b29f24499b9ad90abf7891be61: Scheduling FlushDeltaMemStoresOp(b46b8f828a974a6f8127ecfc403ec57e): perf score=2.188937
I20260812 06:19:25.527426 21263 maintenance_manager.cc:643] P 75fb46b29f24499b9ad90abf7891be61: FlushDeltaMemStoresOp(b46b8f828a974a6f8127ecfc403ec57e) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4208,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:25.527874 21328 maintenance_manager.cc:419] P 75fb46b29f24499b9ad90abf7891be61: Scheduling MajorDeltaCompactionOp(b46b8f828a974a6f8127ecfc403ec57e): perf score=1.000000
I20260812 06:19:25.704984 21263 maintenance_manager.cc:643] P 75fb46b29f24499b9ad90abf7891be61: MajorDeltaCompactionOp(b46b8f828a974a6f8127ecfc403ec57e) complete. Timing: real 0.177s	user 0.120s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":484,"lbm_read_time_us":12389,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28011,"lbm_writes_lt_1ms":543,"mutex_wait_us":262,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14464,"update_count":2500}
I20260812 06:19:25.705611 21328 maintenance_manager.cc:419] P 75fb46b29f24499b9ad90abf7891be61: Scheduling FlushDeltaMemStoresOp(b46b8f828a974a6f8127ecfc403ec57e): perf score=14.095187
I20260812 06:19:25.756385 21263 maintenance_manager.cc:643] P 75fb46b29f24499b9ad90abf7891be61: FlushDeltaMemStoresOp(b46b8f828a974a6f8127ecfc403ec57e) complete. Timing: real 0.051s	user 0.030s	sys 0.011s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":18938,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:25.756932 21328 maintenance_manager.cc:419] P 75fb46b29f24499b9ad90abf7891be61: Scheduling FlushDeltaMemStoresOp(b46b8f828a974a6f8127ecfc403ec57e): perf score=2.188937
I20260812 06:19:25.778175 21263 maintenance_manager.cc:643] P 75fb46b29f24499b9ad90abf7891be61: FlushDeltaMemStoresOp(b46b8f828a974a6f8127ecfc403ec57e) complete. Timing: real 0.021s	user 0.011s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4221,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:25.778760 21328 maintenance_manager.cc:419] P 75fb46b29f24499b9ad90abf7891be61: Scheduling MajorDeltaCompactionOp(b46b8f828a974a6f8127ecfc403ec57e): perf score=1.000000
I20260812 06:19:25.964839 21263 maintenance_manager.cc:643] P 75fb46b29f24499b9ad90abf7891be61: MajorDeltaCompactionOp(b46b8f828a974a6f8127ecfc403ec57e) complete. Timing: real 0.186s	user 0.130s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":482,"lbm_read_time_us":11517,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32364,"lbm_writes_lt_1ms":543,"mutex_wait_us":25,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":20224,"update_count":2500}
I20260812 06:19:25.965400 21328 maintenance_manager.cc:419] P 75fb46b29f24499b9ad90abf7891be61: Scheduling FlushDeltaMemStoresOp(b46b8f828a974a6f8127ecfc403ec57e): perf score=14.095187
I20260812 06:19:26.016601 21263 maintenance_manager.cc:643] P 75fb46b29f24499b9ad90abf7891be61: FlushDeltaMemStoresOp(b46b8f828a974a6f8127ecfc403ec57e) complete. Timing: real 0.051s	user 0.034s	sys 0.015s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":25298,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:19:26.017184 21328 maintenance_manager.cc:419] P 75fb46b29f24499b9ad90abf7891be61: Scheduling FlushDeltaMemStoresOp(b46b8f828a974a6f8127ecfc403ec57e): perf score=2.188937
I20260812 06:19:26.032874 21263 maintenance_manager.cc:643] P 75fb46b29f24499b9ad90abf7891be61: FlushDeltaMemStoresOp(b46b8f828a974a6f8127ecfc403ec57e) complete. Timing: real 0.015s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5964,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:26.033601 21328 maintenance_manager.cc:419] P 75fb46b29f24499b9ad90abf7891be61: Scheduling MajorDeltaCompactionOp(b46b8f828a974a6f8127ecfc403ec57e): perf score=1.000000
I20260812 06:19:26.221511 21263 maintenance_manager.cc:643] P 75fb46b29f24499b9ad90abf7891be61: MajorDeltaCompactionOp(b46b8f828a974a6f8127ecfc403ec57e) complete. Timing: real 0.188s	user 0.119s	sys 0.059s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":580,"lbm_read_time_us":12898,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30148,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9088,"update_count":2500}
I20260812 06:19:26.225147 21328 maintenance_manager.cc:419] P 75fb46b29f24499b9ad90abf7891be61: Scheduling FlushDeltaMemStoresOp(b46b8f828a974a6f8127ecfc403ec57e): perf score=14.095187
I20260812 06:19:26.277267 21263 maintenance_manager.cc:643] P 75fb46b29f24499b9ad90abf7891be61: FlushDeltaMemStoresOp(b46b8f828a974a6f8127ecfc403ec57e) complete. Timing: real 0.052s	user 0.033s	sys 0.015s Metrics: {"bytes_written":16409930,"delete_count":0,"lbm_write_time_us":23292,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:26.277734 21328 maintenance_manager.cc:419] P 75fb46b29f24499b9ad90abf7891be61: Scheduling FlushDeltaMemStoresOp(b46b8f828a974a6f8127ecfc403ec57e): perf score=2.188937
I20260812 06:19:26.288555 21263 maintenance_manager.cc:643] P 75fb46b29f24499b9ad90abf7891be61: FlushDeltaMemStoresOp(b46b8f828a974a6f8127ecfc403ec57e) complete. Timing: real 0.011s	user 0.008s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3900,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:26.289194 21328 maintenance_manager.cc:419] P 75fb46b29f24499b9ad90abf7891be61: Scheduling FlushMRSOp(b46b8f828a974a6f8127ecfc403ec57e): perf score=1.000000
I20260812 06:19:26.324119 21263 maintenance_manager.cc:643] P 75fb46b29f24499b9ad90abf7891be61: FlushMRSOp(b46b8f828a974a6f8127ecfc403ec57e) complete. Timing: real 0.035s	user 0.028s	sys 0.006s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":63,"dirs.run_cpu_time_us":226,"dirs.run_wall_time_us":1309,"drs_written":1,"lbm_read_time_us":59,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1756,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:19:26.324860 21328 maintenance_manager.cc:419] P 75fb46b29f24499b9ad90abf7891be61: Scheduling LogGCOp(b46b8f828a974a6f8127ecfc403ec57e): free 132571590 bytes of WAL
I20260812 06:19:26.325170 21263 log_reader.cc:385] T b46b8f828a974a6f8127ecfc403ec57e: removed 13 log segments from log reader
I20260812 06:19:26.325233 21263 log.cc:1079] T b46b8f828a974a6f8127ecfc403ec57e P 75fb46b29f24499b9ad90abf7891be61: Deleting log segment in path: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515555931601-20911-0/minicluster-data/ts-0-root/wals/b46b8f828a974a6f8127ecfc403ec57e/wal-000000028 (ops 132-136)
I20260812 06:19:26.325284 21263 log.cc:1079] T b46b8f828a974a6f8127ecfc403ec57e P 75fb46b29f24499b9ad90abf7891be61: Deleting log segment in path: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515555931601-20911-0/minicluster-data/ts-0-root/wals/b46b8f828a974a6f8127ecfc403ec57e/wal-000000029 (ops 137-140)
I20260812 06:19:26.325320 21263 log.cc:1079] T b46b8f828a974a6f8127ecfc403ec57e P 75fb46b29f24499b9ad90abf7891be61: Deleting log segment in path: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515555931601-20911-0/minicluster-data/ts-0-root/wals/b46b8f828a974a6f8127ecfc403ec57e/wal-000000030 (ops 141-145)
I20260812 06:19:26.325363 21263 log.cc:1079] T b46b8f828a974a6f8127ecfc403ec57e P 75fb46b29f24499b9ad90abf7891be61: Deleting log segment in path: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515555931601-20911-0/minicluster-data/ts-0-root/wals/b46b8f828a974a6f8127ecfc403ec57e/wal-000000031 (ops 146-150)
I20260812 06:19:26.325400 21263 log.cc:1079] T b46b8f828a974a6f8127ecfc403ec57e P 75fb46b29f24499b9ad90abf7891be61: Deleting log segment in path: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515555931601-20911-0/minicluster-data/ts-0-root/wals/b46b8f828a974a6f8127ecfc403ec57e/wal-000000032 (ops 151-155)
I20260812 06:19:26.325436 21263 log.cc:1079] T b46b8f828a974a6f8127ecfc403ec57e P 75fb46b29f24499b9ad90abf7891be61: Deleting log segment in path: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515555931601-20911-0/minicluster-data/ts-0-root/wals/b46b8f828a974a6f8127ecfc403ec57e/wal-000000033 (ops 156-160)
I20260812 06:19:26.325472 21263 log.cc:1079] T b46b8f828a974a6f8127ecfc403ec57e P 75fb46b29f24499b9ad90abf7891be61: Deleting log segment in path: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515555931601-20911-0/minicluster-data/ts-0-root/wals/b46b8f828a974a6f8127ecfc403ec57e/wal-000000034 (ops 161-164)
I20260812 06:19:26.325510 21263 log.cc:1079] T b46b8f828a974a6f8127ecfc403ec57e P 75fb46b29f24499b9ad90abf7891be61: Deleting log segment in path: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515555931601-20911-0/minicluster-data/ts-0-root/wals/b46b8f828a974a6f8127ecfc403ec57e/wal-000000035 (ops 165-169)
I20260812 06:19:26.325546 21263 log.cc:1079] T b46b8f828a974a6f8127ecfc403ec57e P 75fb46b29f24499b9ad90abf7891be61: Deleting log segment in path: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515555931601-20911-0/minicluster-data/ts-0-root/wals/b46b8f828a974a6f8127ecfc403ec57e/wal-000000036 (ops 170-174)
I20260812 06:19:26.325582 21263 log.cc:1079] T b46b8f828a974a6f8127ecfc403ec57e P 75fb46b29f24499b9ad90abf7891be61: Deleting log segment in path: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515555931601-20911-0/minicluster-data/ts-0-root/wals/b46b8f828a974a6f8127ecfc403ec57e/wal-000000037 (ops 175-179)
I20260812 06:19:26.325618 21263 log.cc:1079] T b46b8f828a974a6f8127ecfc403ec57e P 75fb46b29f24499b9ad90abf7891be61: Deleting log segment in path: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515555931601-20911-0/minicluster-data/ts-0-root/wals/b46b8f828a974a6f8127ecfc403ec57e/wal-000000038 (ops 180-184)
I20260812 06:19:26.325655 21263 log.cc:1079] T b46b8f828a974a6f8127ecfc403ec57e P 75fb46b29f24499b9ad90abf7891be61: Deleting log segment in path: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515555931601-20911-0/minicluster-data/ts-0-root/wals/b46b8f828a974a6f8127ecfc403ec57e/wal-000000039 (ops 185-189)
I20260812 06:19:26.325691 21263 log.cc:1079] T b46b8f828a974a6f8127ecfc403ec57e P 75fb46b29f24499b9ad90abf7891be61: Deleting log segment in path: /tmp/dist-test-tasktt_WZu/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515555931601-20911-0/minicluster-data/ts-0-root/wals/b46b8f828a974a6f8127ecfc403ec57e/wal-000000040 (ops 190-194)
I20260812 06:19:26.352404 21263 maintenance_manager.cc:643] P 75fb46b29f24499b9ad90abf7891be61: LogGCOp(b46b8f828a974a6f8127ecfc403ec57e) complete. Timing: real 0.027s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:19:26.352783 21328 maintenance_manager.cc:419] P 75fb46b29f24499b9ad90abf7891be61: Scheduling UndoDeltaBlockGCOp(b46b8f828a974a6f8127ecfc403ec57e): 493 bytes on disk
I20260812 06:19:26.353300 21263 maintenance_manager.cc:643] P 75fb46b29f24499b9ad90abf7891be61: UndoDeltaBlockGCOp(b46b8f828a974a6f8127ecfc403ec57e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4}
I20260812 06:19:26.353902 21328 maintenance_manager.cc:419] P 75fb46b29f24499b9ad90abf7891be61: Scheduling FlushDeltaMemStoresOp(b46b8f828a974a6f8127ecfc403ec57e): perf score=5.165500
I20260812 06:19:26.374601 21263 maintenance_manager.cc:643] P 75fb46b29f24499b9ad90abf7891be61: FlushDeltaMemStoresOp(b46b8f828a974a6f8127ecfc403ec57e) complete. Timing: real 0.021s	user 0.006s	sys 0.013s Metrics: {"bytes_written":6646161,"delete_count":0,"lbm_write_time_us":8987,"lbm_writes_lt_1ms":165,"reinsert_count":0,"update_count":810}
I20260812 06:19:26.375154 21328 maintenance_manager.cc:419] P 75fb46b29f24499b9ad90abf7891be61: Scheduling FlushDeltaMemStoresOp(b46b8f828a974a6f8127ecfc403ec57e): perf score=1.000000
I20260812 06:19:26.380311 21263 maintenance_manager.cc:643] P 75fb46b29f24499b9ad90abf7891be61: FlushDeltaMemStoresOp(b46b8f828a974a6f8127ecfc403ec57e) complete. Timing: real 0.005s	user 0.002s	sys 0.001s Metrics: {"bytes_written":1559102,"delete_count":0,"lbm_write_time_us":1522,"lbm_writes_lt_1ms":41,"reinsert_count":0,"update_count":190}
I20260812 06:19:26.380699 21328 maintenance_manager.cc:419] P 75fb46b29f24499b9ad90abf7891be61: Scheduling MajorDeltaCompactionOp(b46b8f828a974a6f8127ecfc403ec57e): perf score=1.000000
I20260812 06:19:26.427457 20911 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.830s	user 1.812s	sys 0.181s
I20260812 06:19:26.522248 20911 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.094s	user 0.001s	sys 0.000s
I20260812 06:19:26.522751 20911 tablet_server.cc:179] TabletServer@127.20.107.193:0 shutting down...
I20260812 06:19:26.601503 21263 maintenance_manager.cc:643] P 75fb46b29f24499b9ad90abf7891be61: MajorDeltaCompactionOp(b46b8f828a974a6f8127ecfc403ec57e) complete. Timing: real 0.221s	user 0.152s	sys 0.069s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020714,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1086,"lbm_read_time_us":19493,"lbm_reads_lt_1ms":770,"lbm_write_time_us":38826,"lbm_writes_lt_1ms":743,"mutex_wait_us":119,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":37248,"thread_start_us":93,"threads_started":1,"update_count":3500}
I20260812 06:19:26.602435 20911 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:26.602828 20911 tablet_replica.cc:333] T b46b8f828a974a6f8127ecfc403ec57e P 75fb46b29f24499b9ad90abf7891be61: stopping tablet replica
I20260812 06:19:26.602982 20911 raft_consensus.cc:2243] T b46b8f828a974a6f8127ecfc403ec57e P 75fb46b29f24499b9ad90abf7891be61 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:26.603178 20911 raft_consensus.cc:2272] T b46b8f828a974a6f8127ecfc403ec57e P 75fb46b29f24499b9ad90abf7891be61 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:26.617566 20911 tablet_server.cc:196] TabletServer@127.20.107.193:0 shutdown complete.
I20260812 06:19:26.660040 20911 master.cc:562] Master@127.20.107.254:44665 shutting down...
I20260812 06:19:26.663939 20911 raft_consensus.cc:2243] T 00000000000000000000000000000000 P fb15ec257f4144e58d6bca7730bcfac4 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:26.664156 20911 raft_consensus.cc:2272] T 00000000000000000000000000000000 P fb15ec257f4144e58d6bca7730bcfac4 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:26.664256 20911 tablet_replica.cc:333] T 00000000000000000000000000000000 P fb15ec257f4144e58d6bca7730bcfac4: stopping tablet replica
I20260812 06:19:26.676671 20911 master.cc:584] Master@127.20.107.254:44665 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5383 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10818 ms total)

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