[==========] 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:16:40.775461 25173 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.24.149.126:44953
I20260812 06:16:40.776486 25173 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:16:40.777100 25173 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:40.783326 25183 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:16:40.783337 25186 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:16:40.783571 25173 server_base.cc:1061] running on GCE node
W20260812 06:16:40.783650 25189 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:16:40.784106 25173 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:40.784197 25173 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:16:40.784232 25173 hybrid_clock.cc:648] HybridClock initialized: now 1786515400784230 us; error 0 us; skew 500 ppm
I20260812 06:16:40.786029 25173 webserver.cc:533] Webserver started at http://127.24.149.126:40723/ using document root <none> and password file <none>
I20260812 06:16:40.786566 25173 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:40.786626 25173 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:40.786821 25173 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:40.788580 25173 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515400764805-25173-0/minicluster-data/master-0-root/instance:
uuid: "7281e9723abe41aaa5ad9122f86df63a"
format_stamp: "Formatted at 2026-08-12 06:16:40 on dist-test-slave-n326"
I20260812 06:16:40.792411 25173 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.004s	sys 0.000s
I20260812 06:16:40.794728 25196 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:16:40.795917 25173 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:16:40.796032 25173 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515400764805-25173-0/minicluster-data/master-0-root
uuid: "7281e9723abe41aaa5ad9122f86df63a"
format_stamp: "Formatted at 2026-08-12 06:16:40 on dist-test-slave-n326"
I20260812 06:16:40.796125 25173 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515400764805-25173-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515400764805-25173-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515400764805-25173-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:16:40.811635 25173 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:40.812331 25173 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:16:40.812502 25173 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:40.820312 25280 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.24.149.126:44953 every 8 connection(s)
I20260812 06:16:40.820307 25173 rpc_server.cc:307] RPC server started. Bound to: 127.24.149.126:44953
I20260812 06:16:40.822716 25282 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:16:40.828517 25282 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 7281e9723abe41aaa5ad9122f86df63a: Bootstrap starting.
I20260812 06:16:40.830920 25282 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 7281e9723abe41aaa5ad9122f86df63a: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:40.831908 25282 log.cc:826] T 00000000000000000000000000000000 P 7281e9723abe41aaa5ad9122f86df63a: Log is configured to *not* fsync() on all Append() calls
I20260812 06:16:40.833897 25282 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 7281e9723abe41aaa5ad9122f86df63a: No bootstrap required, opened a new log
I20260812 06:16:40.836833 25282 raft_consensus.cc:359] T 00000000000000000000000000000000 P 7281e9723abe41aaa5ad9122f86df63a [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7281e9723abe41aaa5ad9122f86df63a" member_type: VOTER }
I20260812 06:16:40.837003 25282 raft_consensus.cc:385] T 00000000000000000000000000000000 P 7281e9723abe41aaa5ad9122f86df63a [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:40.837085 25282 raft_consensus.cc:740] T 00000000000000000000000000000000 P 7281e9723abe41aaa5ad9122f86df63a [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 7281e9723abe41aaa5ad9122f86df63a, State: Initialized, Role: FOLLOWER
I20260812 06:16:40.837700 25282 consensus_queue.cc:260] T 00000000000000000000000000000000 P 7281e9723abe41aaa5ad9122f86df63a [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: "7281e9723abe41aaa5ad9122f86df63a" member_type: VOTER }
I20260812 06:16:40.837841 25282 raft_consensus.cc:399] T 00000000000000000000000000000000 P 7281e9723abe41aaa5ad9122f86df63a [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:40.837941 25282 raft_consensus.cc:493] T 00000000000000000000000000000000 P 7281e9723abe41aaa5ad9122f86df63a [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:40.838086 25282 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 7281e9723abe41aaa5ad9122f86df63a [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:40.838913 25282 raft_consensus.cc:515] T 00000000000000000000000000000000 P 7281e9723abe41aaa5ad9122f86df63a [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7281e9723abe41aaa5ad9122f86df63a" member_type: VOTER }
I20260812 06:16:40.839385 25282 leader_election.cc:304] T 00000000000000000000000000000000 P 7281e9723abe41aaa5ad9122f86df63a [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: 7281e9723abe41aaa5ad9122f86df63a; no voters: 
I20260812 06:16:40.839713 25282 leader_election.cc:290] T 00000000000000000000000000000000 P 7281e9723abe41aaa5ad9122f86df63a [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:40.839900 25288 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 7281e9723abe41aaa5ad9122f86df63a [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:40.840153 25288 raft_consensus.cc:697] T 00000000000000000000000000000000 P 7281e9723abe41aaa5ad9122f86df63a [term 1 LEADER]: Becoming Leader. State: Replica: 7281e9723abe41aaa5ad9122f86df63a, State: Running, Role: LEADER
I20260812 06:16:40.840584 25288 consensus_queue.cc:237] T 00000000000000000000000000000000 P 7281e9723abe41aaa5ad9122f86df63a [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: "7281e9723abe41aaa5ad9122f86df63a" member_type: VOTER }
I20260812 06:16:40.840803 25282 sys_catalog.cc:565] T 00000000000000000000000000000000 P 7281e9723abe41aaa5ad9122f86df63a [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:16:40.842562 25289 sys_catalog.cc:455] T 00000000000000000000000000000000 P 7281e9723abe41aaa5ad9122f86df63a [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "7281e9723abe41aaa5ad9122f86df63a" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7281e9723abe41aaa5ad9122f86df63a" member_type: VOTER } }
I20260812 06:16:40.842686 25289 sys_catalog.cc:458] T 00000000000000000000000000000000 P 7281e9723abe41aaa5ad9122f86df63a [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:40.843009 25290 sys_catalog.cc:455] T 00000000000000000000000000000000 P 7281e9723abe41aaa5ad9122f86df63a [sys.catalog]: SysCatalogTable state changed. Reason: New leader 7281e9723abe41aaa5ad9122f86df63a. Latest consensus state: current_term: 1 leader_uuid: "7281e9723abe41aaa5ad9122f86df63a" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7281e9723abe41aaa5ad9122f86df63a" member_type: VOTER } }
I20260812 06:16:40.843107 25290 sys_catalog.cc:458] T 00000000000000000000000000000000 P 7281e9723abe41aaa5ad9122f86df63a [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:40.843176 25173 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
W20260812 06:16:40.844985 25310 catalog_manager.cc:1594] T 00000000000000000000000000000000 P 7281e9723abe41aaa5ad9122f86df63a: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:16:40.845048 25310 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:16:40.845134 25307 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:16:40.845824 25307 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:16:40.850224 25307 catalog_manager.cc:1383] Generated new cluster ID: beff8f928acc4bef9ade88e3e9132045
I20260812 06:16:40.850287 25307 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:16:40.873473 25307 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:16:40.874671 25307 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:16:40.884156 25307 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 7281e9723abe41aaa5ad9122f86df63a: Generated new TSK 0
I20260812 06:16:40.884868 25307 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:16:40.907902 25173 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:40.910689 25322 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:16:40.910703 25325 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:16:40.910715 25320 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:16:40.911309 25173 server_base.cc:1061] running on GCE node
I20260812 06:16:40.911482 25173 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:40.911530 25173 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:16:40.911556 25173 hybrid_clock.cc:648] HybridClock initialized: now 1786515400911555 us; error 0 us; skew 500 ppm
I20260812 06:16:40.912498 25173 webserver.cc:533] Webserver started at http://127.24.149.65:42703/ using document root <none> and password file <none>
I20260812 06:16:40.912675 25173 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:40.912736 25173 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:40.912813 25173 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:40.913266 25173 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515400764805-25173-0/minicluster-data/ts-0-root/instance:
uuid: "ed6f53a587794af0b54ab1fa07006aca"
format_stamp: "Formatted at 2026-08-12 06:16:40 on dist-test-slave-n326"
I20260812 06:16:40.915103 25173 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.002s	sys 0.001s
I20260812 06:16:40.916178 25331 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:16:40.916440 25173 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:16:40.916515 25173 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515400764805-25173-0/minicluster-data/ts-0-root
uuid: "ed6f53a587794af0b54ab1fa07006aca"
format_stamp: "Formatted at 2026-08-12 06:16:40 on dist-test-slave-n326"
I20260812 06:16:40.916604 25173 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515400764805-25173-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515400764805-25173-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515400764805-25173-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:16:40.926117 25173 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:40.926533 25173 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:40.926967 25173 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:16:40.927822 25173 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:16:40.927875 25173 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:40.927939 25173 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:16:40.927979 25173 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:40.935000 25173 rpc_server.cc:307] RPC server started. Bound to: 127.24.149.65:34493
I20260812 06:16:40.935031 25430 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.24.149.65:34493 every 8 connection(s)
I20260812 06:16:40.945083 25432 heartbeater.cc:344] Connected to a master server at 127.24.149.126:44953
I20260812 06:16:40.945335 25432 heartbeater.cc:461] Registering TS with master...
I20260812 06:16:40.945842 25432 heartbeater.cc:507] Master 127.24.149.126:44953 requested a full tablet report, sending...
I20260812 06:16:40.947285 25225 ts_manager.cc:194] Registered new tserver with Master: ed6f53a587794af0b54ab1fa07006aca (127.24.149.65:34493)
I20260812 06:16:40.947978 25173 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.012349557s
I20260812 06:16:40.948637 25225 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:36376
I20260812 06:16:40.957038 25225 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:36382:
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:16:40.970888 25376 tablet_service.cc:1511] Processing CreateTablet for tablet e62d1537e9c94e87be8a3097d2e3dfa1 (DEFAULT_TABLE table=heavy-update-compaction-test [id=a979615e6efc48109022832d63bdc164]), partition=
I20260812 06:16:40.971392 25376 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet e62d1537e9c94e87be8a3097d2e3dfa1. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:16:40.973651 25460 tablet_bootstrap.cc:492] T e62d1537e9c94e87be8a3097d2e3dfa1 P ed6f53a587794af0b54ab1fa07006aca: Bootstrap starting.
I20260812 06:16:40.974630 25460 tablet_bootstrap.cc:654] T e62d1537e9c94e87be8a3097d2e3dfa1 P ed6f53a587794af0b54ab1fa07006aca: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:40.975891 25460 tablet_bootstrap.cc:492] T e62d1537e9c94e87be8a3097d2e3dfa1 P ed6f53a587794af0b54ab1fa07006aca: No bootstrap required, opened a new log
I20260812 06:16:40.975978 25460 ts_tablet_manager.cc:1403] T e62d1537e9c94e87be8a3097d2e3dfa1 P ed6f53a587794af0b54ab1fa07006aca: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:16:40.976457 25460 raft_consensus.cc:359] T e62d1537e9c94e87be8a3097d2e3dfa1 P ed6f53a587794af0b54ab1fa07006aca [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ed6f53a587794af0b54ab1fa07006aca" member_type: VOTER last_known_addr { host: "127.24.149.65" port: 34493 } }
I20260812 06:16:40.976557 25460 raft_consensus.cc:385] T e62d1537e9c94e87be8a3097d2e3dfa1 P ed6f53a587794af0b54ab1fa07006aca [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:40.976584 25460 raft_consensus.cc:740] T e62d1537e9c94e87be8a3097d2e3dfa1 P ed6f53a587794af0b54ab1fa07006aca [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: ed6f53a587794af0b54ab1fa07006aca, State: Initialized, Role: FOLLOWER
I20260812 06:16:40.976773 25460 consensus_queue.cc:260] T e62d1537e9c94e87be8a3097d2e3dfa1 P ed6f53a587794af0b54ab1fa07006aca [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: "ed6f53a587794af0b54ab1fa07006aca" member_type: VOTER last_known_addr { host: "127.24.149.65" port: 34493 } }
I20260812 06:16:40.976845 25460 raft_consensus.cc:399] T e62d1537e9c94e87be8a3097d2e3dfa1 P ed6f53a587794af0b54ab1fa07006aca [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:40.976890 25460 raft_consensus.cc:493] T e62d1537e9c94e87be8a3097d2e3dfa1 P ed6f53a587794af0b54ab1fa07006aca [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:40.976948 25460 raft_consensus.cc:3060] T e62d1537e9c94e87be8a3097d2e3dfa1 P ed6f53a587794af0b54ab1fa07006aca [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:40.977711 25460 raft_consensus.cc:515] T e62d1537e9c94e87be8a3097d2e3dfa1 P ed6f53a587794af0b54ab1fa07006aca [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ed6f53a587794af0b54ab1fa07006aca" member_type: VOTER last_known_addr { host: "127.24.149.65" port: 34493 } }
I20260812 06:16:40.977859 25460 leader_election.cc:304] T e62d1537e9c94e87be8a3097d2e3dfa1 P ed6f53a587794af0b54ab1fa07006aca [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: ed6f53a587794af0b54ab1fa07006aca; no voters: 
I20260812 06:16:40.978124 25460 leader_election.cc:290] T e62d1537e9c94e87be8a3097d2e3dfa1 P ed6f53a587794af0b54ab1fa07006aca [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:40.978227 25464 raft_consensus.cc:2804] T e62d1537e9c94e87be8a3097d2e3dfa1 P ed6f53a587794af0b54ab1fa07006aca [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:40.978428 25464 raft_consensus.cc:697] T e62d1537e9c94e87be8a3097d2e3dfa1 P ed6f53a587794af0b54ab1fa07006aca [term 1 LEADER]: Becoming Leader. State: Replica: ed6f53a587794af0b54ab1fa07006aca, State: Running, Role: LEADER
I20260812 06:16:40.978765 25432 heartbeater.cc:499] Master 127.24.149.126:44953 was elected leader, sending a full tablet report...
I20260812 06:16:40.978860 25464 consensus_queue.cc:237] T e62d1537e9c94e87be8a3097d2e3dfa1 P ed6f53a587794af0b54ab1fa07006aca [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: "ed6f53a587794af0b54ab1fa07006aca" member_type: VOTER last_known_addr { host: "127.24.149.65" port: 34493 } }
I20260812 06:16:40.978478 25460 ts_tablet_manager.cc:1434] T e62d1537e9c94e87be8a3097d2e3dfa1 P ed6f53a587794af0b54ab1fa07006aca: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:16:40.981673 25225 catalog_manager.cc:5719] T e62d1537e9c94e87be8a3097d2e3dfa1 P ed6f53a587794af0b54ab1fa07006aca reported cstate change: term changed from 0 to 1, leader changed from <none> to ed6f53a587794af0b54ab1fa07006aca (127.24.149.65). New cstate: current_term: 1 leader_uuid: "ed6f53a587794af0b54ab1fa07006aca" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "ed6f53a587794af0b54ab1fa07006aca" member_type: VOTER last_known_addr { host: "127.24.149.65" port: 34493 } health_report { overall_health: HEALTHY } } }
I20260812 06:16:41.048657 25173 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.056s	user 0.021s	sys 0.005s
I20260812 06:16:41.186219 25435 maintenance_manager.cc:419] P ed6f53a587794af0b54ab1fa07006aca: Scheduling FlushMRSOp(e62d1537e9c94e87be8a3097d2e3dfa1): perf score=19.054940
I20260812 06:16:41.375442 25345 maintenance_manager.cc:643] P ed6f53a587794af0b54ab1fa07006aca: FlushMRSOp(e62d1537e9c94e87be8a3097d2e3dfa1) complete. Timing: real 0.189s	user 0.155s	sys 0.032s Metrics: {"bytes_written":13210027,"cfile_init":1,"compiler_manager_pool.queue_time_us":350,"delete_count":0,"dirs.queue_time_us":47,"dirs.run_cpu_time_us":210,"dirs.run_wall_time_us":2089,"drs_written":1,"lbm_read_time_us":81,"lbm_reads_lt_1ms":4,"lbm_write_time_us":47082,"lbm_writes_lt_1ms":779,"mutex_wait_us":202,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":98560,"thread_start_us":145,"threads_started":1,"update_count":1610}
I20260812 06:16:41.376750 25435 maintenance_manager.cc:419] P ed6f53a587794af0b54ab1fa07006aca: Scheduling LogGCOp(e62d1537e9c94e87be8a3097d2e3dfa1): free 20743880 bytes of WAL
I20260812 06:16:41.377079 25345 log_reader.cc:385] T e62d1537e9c94e87be8a3097d2e3dfa1: removed 2 log segments from log reader
I20260812 06:16:41.377146 25345 log.cc:1079] T e62d1537e9c94e87be8a3097d2e3dfa1 P ed6f53a587794af0b54ab1fa07006aca: Deleting log segment in path: /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515400764805-25173-0/minicluster-data/ts-0-root/wals/e62d1537e9c94e87be8a3097d2e3dfa1/wal-000000001 (ops 1-6)
I20260812 06:16:41.377197 25345 log.cc:1079] T e62d1537e9c94e87be8a3097d2e3dfa1 P ed6f53a587794af0b54ab1fa07006aca: Deleting log segment in path: /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515400764805-25173-0/minicluster-data/ts-0-root/wals/e62d1537e9c94e87be8a3097d2e3dfa1/wal-000000002 (ops 7-11)
I20260812 06:16:41.382921 25345 maintenance_manager.cc:643] P ed6f53a587794af0b54ab1fa07006aca: LogGCOp(e62d1537e9c94e87be8a3097d2e3dfa1) complete. Timing: real 0.006s	user 0.001s	sys 0.004s Metrics: {}
I20260812 06:16:41.383302 25435 maintenance_manager.cc:419] P ed6f53a587794af0b54ab1fa07006aca: Scheduling UndoDeltaBlockGCOp(e62d1537e9c94e87be8a3097d2e3dfa1): 16411393 bytes on disk
I20260812 06:16:41.383859 25345 maintenance_manager.cc:643] P ed6f53a587794af0b54ab1fa07006aca: UndoDeltaBlockGCOp(e62d1537e9c94e87be8a3097d2e3dfa1) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":62,"lbm_reads_lt_1ms":4}
I20260812 06:16:41.384253 25435 maintenance_manager.cc:419] P ed6f53a587794af0b54ab1fa07006aca: Scheduling FlushDeltaMemStoresOp(e62d1537e9c94e87be8a3097d2e3dfa1): perf score=2.188937
I20260812 06:16:41.403743 25345 maintenance_manager.cc:643] P ed6f53a587794af0b54ab1fa07006aca: FlushDeltaMemStoresOp(e62d1537e9c94e87be8a3097d2e3dfa1) complete. Timing: real 0.019s	user 0.011s	sys 0.007s Metrics: {"bytes_written":3610359,"delete_count":0,"lbm_write_time_us":4491,"lbm_writes_lt_1ms":91,"reinsert_count":0,"update_count":440}
I20260812 06:16:41.404258 25435 maintenance_manager.cc:419] P ed6f53a587794af0b54ab1fa07006aca: Scheduling FlushDeltaMemStoresOp(e62d1537e9c94e87be8a3097d2e3dfa1): perf score=2.188937
I20260812 06:16:41.417232 25345 maintenance_manager.cc:643] P ed6f53a587794af0b54ab1fa07006aca: FlushDeltaMemStoresOp(e62d1537e9c94e87be8a3097d2e3dfa1) complete. Timing: real 0.013s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4861,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:41.417717 25435 maintenance_manager.cc:419] P ed6f53a587794af0b54ab1fa07006aca: Scheduling MajorDeltaCompactionOp(e62d1537e9c94e87be8a3097d2e3dfa1): perf score=1.000000
I20260812 06:16:41.589638 25345 maintenance_manager.cc:643] P ed6f53a587794af0b54ab1fa07006aca: MajorDeltaCompactionOp(e62d1537e9c94e87be8a3097d2e3dfa1) complete. Timing: real 0.172s	user 0.104s	sys 0.068s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774791,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":611,"lbm_read_time_us":11561,"lbm_reads_lt_1ms":569,"lbm_write_time_us":29445,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"thread_start_us":332,"threads_started":5,"update_count":2500}
I20260812 06:16:41.590250 25435 maintenance_manager.cc:419] P ed6f53a587794af0b54ab1fa07006aca: Scheduling FlushDeltaMemStoresOp(e62d1537e9c94e87be8a3097d2e3dfa1): perf score=10.126437
I20260812 06:16:41.629272 25345 maintenance_manager.cc:643] P ed6f53a587794af0b54ab1fa07006aca: FlushDeltaMemStoresOp(e62d1537e9c94e87be8a3097d2e3dfa1) complete. Timing: real 0.039s	user 0.017s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":15953,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:41.629746 25435 maintenance_manager.cc:419] P ed6f53a587794af0b54ab1fa07006aca: Scheduling FlushDeltaMemStoresOp(e62d1537e9c94e87be8a3097d2e3dfa1): perf score=2.188937
I20260812 06:16:41.640743 25345 maintenance_manager.cc:643] P ed6f53a587794af0b54ab1fa07006aca: FlushDeltaMemStoresOp(e62d1537e9c94e87be8a3097d2e3dfa1) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3969,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:41.641228 25435 maintenance_manager.cc:419] P ed6f53a587794af0b54ab1fa07006aca: Scheduling MajorDeltaCompactionOp(e62d1537e9c94e87be8a3097d2e3dfa1): perf score=1.000000
I20260812 06:16:41.765033 25345 maintenance_manager.cc:643] P ed6f53a587794af0b54ab1fa07006aca: MajorDeltaCompactionOp(e62d1537e9c94e87be8a3097d2e3dfa1) complete. Timing: real 0.124s	user 0.084s	sys 0.040s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":266,"lbm_read_time_us":9160,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23796,"lbm_writes_lt_1ms":443,"mutex_wait_us":49,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":61312,"update_count":2000}
I20260812 06:16:41.765625 25435 maintenance_manager.cc:419] P ed6f53a587794af0b54ab1fa07006aca: Scheduling FlushDeltaMemStoresOp(e62d1537e9c94e87be8a3097d2e3dfa1): perf score=10.126437
I20260812 06:16:41.808544 25345 maintenance_manager.cc:643] P ed6f53a587794af0b54ab1fa07006aca: FlushDeltaMemStoresOp(e62d1537e9c94e87be8a3097d2e3dfa1) complete. Timing: real 0.043s	user 0.025s	sys 0.011s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15646,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:16:41.809125 25435 maintenance_manager.cc:419] P ed6f53a587794af0b54ab1fa07006aca: Scheduling FlushDeltaMemStoresOp(e62d1537e9c94e87be8a3097d2e3dfa1): perf score=2.188937
I20260812 06:16:41.819653 25345 maintenance_manager.cc:643] P ed6f53a587794af0b54ab1fa07006aca: FlushDeltaMemStoresOp(e62d1537e9c94e87be8a3097d2e3dfa1) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4088,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:41.820185 25435 maintenance_manager.cc:419] P ed6f53a587794af0b54ab1fa07006aca: Scheduling MajorDeltaCompactionOp(e62d1537e9c94e87be8a3097d2e3dfa1): perf score=1.000000
I20260812 06:16:41.947619 25345 maintenance_manager.cc:643] P ed6f53a587794af0b54ab1fa07006aca: MajorDeltaCompactionOp(e62d1537e9c94e87be8a3097d2e3dfa1) complete. Timing: real 0.127s	user 0.107s	sys 0.020s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":557,"lbm_read_time_us":9088,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24228,"lbm_writes_lt_1ms":443,"mutex_wait_us":41,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2000}
I20260812 06:16:41.948222 25435 maintenance_manager.cc:419] P ed6f53a587794af0b54ab1fa07006aca: Scheduling FlushDeltaMemStoresOp(e62d1537e9c94e87be8a3097d2e3dfa1): perf score=10.126437
I20260812 06:16:41.997916 25345 maintenance_manager.cc:643] P ed6f53a587794af0b54ab1fa07006aca: FlushDeltaMemStoresOp(e62d1537e9c94e87be8a3097d2e3dfa1) complete. Timing: real 0.049s	user 0.024s	sys 0.011s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":16916,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:41.998420 25435 maintenance_manager.cc:419] P ed6f53a587794af0b54ab1fa07006aca: Scheduling FlushDeltaMemStoresOp(e62d1537e9c94e87be8a3097d2e3dfa1): perf score=2.188937
I20260812 06:16:42.009850 25345 maintenance_manager.cc:643] P ed6f53a587794af0b54ab1fa07006aca: FlushDeltaMemStoresOp(e62d1537e9c94e87be8a3097d2e3dfa1) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4133,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:42.010541 25435 maintenance_manager.cc:419] P ed6f53a587794af0b54ab1fa07006aca: Scheduling MajorDeltaCompactionOp(e62d1537e9c94e87be8a3097d2e3dfa1): perf score=1.000000
I20260812 06:16:42.139907 25345 maintenance_manager.cc:643] P ed6f53a587794af0b54ab1fa07006aca: MajorDeltaCompactionOp(e62d1537e9c94e87be8a3097d2e3dfa1) complete. Timing: real 0.129s	user 0.097s	sys 0.031s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1013,"lbm_read_time_us":10282,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24784,"lbm_writes_lt_1ms":443,"mutex_wait_us":321,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":17280,"update_count":2000}
I20260812 06:16:42.140508 25435 maintenance_manager.cc:419] P ed6f53a587794af0b54ab1fa07006aca: Scheduling FlushDeltaMemStoresOp(e62d1537e9c94e87be8a3097d2e3dfa1): perf score=10.126437
I20260812 06:16:42.193568 25345 maintenance_manager.cc:643] P ed6f53a587794af0b54ab1fa07006aca: FlushDeltaMemStoresOp(e62d1537e9c94e87be8a3097d2e3dfa1) complete. Timing: real 0.053s	user 0.029s	sys 0.018s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":18468,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:42.194149 25435 maintenance_manager.cc:419] P ed6f53a587794af0b54ab1fa07006aca: Scheduling FlushDeltaMemStoresOp(e62d1537e9c94e87be8a3097d2e3dfa1): perf score=2.188937
I20260812 06:16:42.208559 25345 maintenance_manager.cc:643] P ed6f53a587794af0b54ab1fa07006aca: FlushDeltaMemStoresOp(e62d1537e9c94e87be8a3097d2e3dfa1) complete. Timing: real 0.014s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5537,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:42.209545 25435 maintenance_manager.cc:419] P ed6f53a587794af0b54ab1fa07006aca: Scheduling MajorDeltaCompactionOp(e62d1537e9c94e87be8a3097d2e3dfa1): perf score=1.000000
I20260812 06:16:42.374774 25345 maintenance_manager.cc:643] P ed6f53a587794af0b54ab1fa07006aca: MajorDeltaCompactionOp(e62d1537e9c94e87be8a3097d2e3dfa1) complete. Timing: real 0.165s	user 0.111s	sys 0.044s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1152,"lbm_read_time_us":10708,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26912,"lbm_writes_lt_1ms":443,"mutex_wait_us":353,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":1408,"update_count":2000}
I20260812 06:16:42.375452 25435 maintenance_manager.cc:419] P ed6f53a587794af0b54ab1fa07006aca: Scheduling FlushDeltaMemStoresOp(e62d1537e9c94e87be8a3097d2e3dfa1): perf score=10.126437
I20260812 06:16:42.425046 25345 maintenance_manager.cc:643] P ed6f53a587794af0b54ab1fa07006aca: FlushDeltaMemStoresOp(e62d1537e9c94e87be8a3097d2e3dfa1) complete. Timing: real 0.049s	user 0.021s	sys 0.020s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":19361,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":302,"reinsert_count":0,"update_count":1500}
I20260812 06:16:42.425570 25435 maintenance_manager.cc:419] P ed6f53a587794af0b54ab1fa07006aca: Scheduling FlushDeltaMemStoresOp(e62d1537e9c94e87be8a3097d2e3dfa1): perf score=2.188937
I20260812 06:16:42.438687 25345 maintenance_manager.cc:643] P ed6f53a587794af0b54ab1fa07006aca: FlushDeltaMemStoresOp(e62d1537e9c94e87be8a3097d2e3dfa1) complete. Timing: real 0.013s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4953,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:42.439294 25435 maintenance_manager.cc:419] P ed6f53a587794af0b54ab1fa07006aca: Scheduling MajorDeltaCompactionOp(e62d1537e9c94e87be8a3097d2e3dfa1): perf score=1.000000
I20260812 06:16:42.565006 25345 maintenance_manager.cc:643] P ed6f53a587794af0b54ab1fa07006aca: MajorDeltaCompactionOp(e62d1537e9c94e87be8a3097d2e3dfa1) complete. Timing: real 0.126s	user 0.096s	sys 0.029s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":184,"lbm_read_time_us":8422,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24975,"lbm_writes_lt_1ms":443,"mutex_wait_us":42,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:16:42.565729 25435 maintenance_manager.cc:419] P ed6f53a587794af0b54ab1fa07006aca: Scheduling FlushDeltaMemStoresOp(e62d1537e9c94e87be8a3097d2e3dfa1): perf score=10.126437
I20260812 06:16:42.606689 25345 maintenance_manager.cc:643] P ed6f53a587794af0b54ab1fa07006aca: FlushDeltaMemStoresOp(e62d1537e9c94e87be8a3097d2e3dfa1) complete. Timing: real 0.041s	user 0.030s	sys 0.008s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17053,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:42.607267 25435 maintenance_manager.cc:419] P ed6f53a587794af0b54ab1fa07006aca: Scheduling FlushDeltaMemStoresOp(e62d1537e9c94e87be8a3097d2e3dfa1): perf score=2.188937
I20260812 06:16:42.623157 25345 maintenance_manager.cc:643] P ed6f53a587794af0b54ab1fa07006aca: FlushDeltaMemStoresOp(e62d1537e9c94e87be8a3097d2e3dfa1) complete. Timing: real 0.016s	user 0.003s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6125,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:42.623770 25435 maintenance_manager.cc:419] P ed6f53a587794af0b54ab1fa07006aca: Scheduling FlushMRSOp(e62d1537e9c94e87be8a3097d2e3dfa1): perf score=1.000000
I20260812 06:16:42.660312 25345 maintenance_manager.cc:643] P ed6f53a587794af0b54ab1fa07006aca: FlushMRSOp(e62d1537e9c94e87be8a3097d2e3dfa1) complete. Timing: real 0.036s	user 0.026s	sys 0.000s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":75,"dirs.run_cpu_time_us":271,"dirs.run_wall_time_us":1314,"drs_written":1,"lbm_read_time_us":63,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1533,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:16:42.661289 25435 maintenance_manager.cc:419] P ed6f53a587794af0b54ab1fa07006aca: Scheduling FlushDeltaMemStoresOp(e62d1537e9c94e87be8a3097d2e3dfa1): perf score=3.181125
I20260812 06:16:42.672729 25345 maintenance_manager.cc:643] P ed6f53a587794af0b54ab1fa07006aca: FlushDeltaMemStoresOp(e62d1537e9c94e87be8a3097d2e3dfa1) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4337,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:16:42.673172 25435 maintenance_manager.cc:419] P ed6f53a587794af0b54ab1fa07006aca: Scheduling LogGCOp(e62d1537e9c94e87be8a3097d2e3dfa1): free 124710240 bytes of WAL
I20260812 06:16:42.673393 25345 log_reader.cc:385] T e62d1537e9c94e87be8a3097d2e3dfa1: removed 12 log segments from log reader
I20260812 06:16:42.673439 25345 log.cc:1079] T e62d1537e9c94e87be8a3097d2e3dfa1 P ed6f53a587794af0b54ab1fa07006aca: Deleting log segment in path: /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515400764805-25173-0/minicluster-data/ts-0-root/wals/e62d1537e9c94e87be8a3097d2e3dfa1/wal-000000003 (ops 12-16)
I20260812 06:16:42.673467 25345 log.cc:1079] T e62d1537e9c94e87be8a3097d2e3dfa1 P ed6f53a587794af0b54ab1fa07006aca: Deleting log segment in path: /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515400764805-25173-0/minicluster-data/ts-0-root/wals/e62d1537e9c94e87be8a3097d2e3dfa1/wal-000000004 (ops 17-21)
I20260812 06:16:42.673511 25345 log.cc:1079] T e62d1537e9c94e87be8a3097d2e3dfa1 P ed6f53a587794af0b54ab1fa07006aca: Deleting log segment in path: /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515400764805-25173-0/minicluster-data/ts-0-root/wals/e62d1537e9c94e87be8a3097d2e3dfa1/wal-000000005 (ops 22-26)
I20260812 06:16:42.673556 25345 log.cc:1079] T e62d1537e9c94e87be8a3097d2e3dfa1 P ed6f53a587794af0b54ab1fa07006aca: Deleting log segment in path: /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515400764805-25173-0/minicluster-data/ts-0-root/wals/e62d1537e9c94e87be8a3097d2e3dfa1/wal-000000006 (ops 27-31)
I20260812 06:16:42.673632 25345 log.cc:1079] T e62d1537e9c94e87be8a3097d2e3dfa1 P ed6f53a587794af0b54ab1fa07006aca: Deleting log segment in path: /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515400764805-25173-0/minicluster-data/ts-0-root/wals/e62d1537e9c94e87be8a3097d2e3dfa1/wal-000000007 (ops 32-36)
I20260812 06:16:42.673674 25345 log.cc:1079] T e62d1537e9c94e87be8a3097d2e3dfa1 P ed6f53a587794af0b54ab1fa07006aca: Deleting log segment in path: /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515400764805-25173-0/minicluster-data/ts-0-root/wals/e62d1537e9c94e87be8a3097d2e3dfa1/wal-000000008 (ops 37-41)
I20260812 06:16:42.673713 25345 log.cc:1079] T e62d1537e9c94e87be8a3097d2e3dfa1 P ed6f53a587794af0b54ab1fa07006aca: Deleting log segment in path: /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515400764805-25173-0/minicluster-data/ts-0-root/wals/e62d1537e9c94e87be8a3097d2e3dfa1/wal-000000009 (ops 42-46)
I20260812 06:16:42.673753 25345 log.cc:1079] T e62d1537e9c94e87be8a3097d2e3dfa1 P ed6f53a587794af0b54ab1fa07006aca: Deleting log segment in path: /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515400764805-25173-0/minicluster-data/ts-0-root/wals/e62d1537e9c94e87be8a3097d2e3dfa1/wal-000000010 (ops 47-51)
I20260812 06:16:42.673795 25345 log.cc:1079] T e62d1537e9c94e87be8a3097d2e3dfa1 P ed6f53a587794af0b54ab1fa07006aca: Deleting log segment in path: /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515400764805-25173-0/minicluster-data/ts-0-root/wals/e62d1537e9c94e87be8a3097d2e3dfa1/wal-000000011 (ops 52-56)
I20260812 06:16:42.673837 25345 log.cc:1079] T e62d1537e9c94e87be8a3097d2e3dfa1 P ed6f53a587794af0b54ab1fa07006aca: Deleting log segment in path: /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515400764805-25173-0/minicluster-data/ts-0-root/wals/e62d1537e9c94e87be8a3097d2e3dfa1/wal-000000012 (ops 57-61)
I20260812 06:16:42.673877 25345 log.cc:1079] T e62d1537e9c94e87be8a3097d2e3dfa1 P ed6f53a587794af0b54ab1fa07006aca: Deleting log segment in path: /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515400764805-25173-0/minicluster-data/ts-0-root/wals/e62d1537e9c94e87be8a3097d2e3dfa1/wal-000000013 (ops 62-66)
I20260812 06:16:42.673918 25345 log.cc:1079] T e62d1537e9c94e87be8a3097d2e3dfa1 P ed6f53a587794af0b54ab1fa07006aca: Deleting log segment in path: /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515400764805-25173-0/minicluster-data/ts-0-root/wals/e62d1537e9c94e87be8a3097d2e3dfa1/wal-000000014 (ops 67-71)
I20260812 06:16:42.702550 25345 maintenance_manager.cc:643] P ed6f53a587794af0b54ab1fa07006aca: LogGCOp(e62d1537e9c94e87be8a3097d2e3dfa1) complete. Timing: real 0.029s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:16:42.703014 25435 maintenance_manager.cc:419] P ed6f53a587794af0b54ab1fa07006aca: Scheduling FlushDeltaMemStoresOp(e62d1537e9c94e87be8a3097d2e3dfa1): perf score=2.188937
I20260812 06:16:42.720758 25345 maintenance_manager.cc:643] P ed6f53a587794af0b54ab1fa07006aca: FlushDeltaMemStoresOp(e62d1537e9c94e87be8a3097d2e3dfa1) complete. Timing: real 0.018s	user 0.014s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6149,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:42.721230 25435 maintenance_manager.cc:419] P ed6f53a587794af0b54ab1fa07006aca: Scheduling FlushDeltaMemStoresOp(e62d1537e9c94e87be8a3097d2e3dfa1): perf score=2.188937
I20260812 06:16:42.731027 25345 maintenance_manager.cc:643] P ed6f53a587794af0b54ab1fa07006aca: FlushDeltaMemStoresOp(e62d1537e9c94e87be8a3097d2e3dfa1) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3582,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:42.731537 25435 maintenance_manager.cc:419] P ed6f53a587794af0b54ab1fa07006aca: Scheduling MajorDeltaCompactionOp(e62d1537e9c94e87be8a3097d2e3dfa1): perf score=1.000000
I20260812 06:16:42.929044 25345 maintenance_manager.cc:643] P ed6f53a587794af0b54ab1fa07006aca: MajorDeltaCompactionOp(e62d1537e9c94e87be8a3097d2e3dfa1) complete. Timing: real 0.197s	user 0.158s	sys 0.038s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32979860,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":421,"lbm_read_time_us":12331,"lbm_reads_lt_1ms":775,"lbm_write_time_us":42253,"lbm_writes_lt_1ms":743,"mutex_wait_us":139,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":2304,"thread_start_us":91,"threads_started":1,"update_count":3500}
I20260812 06:16:42.929574 25435 maintenance_manager.cc:419] P ed6f53a587794af0b54ab1fa07006aca: Scheduling UndoDeltaBlockGCOp(e62d1537e9c94e87be8a3097d2e3dfa1): 472 bytes on disk
I20260812 06:16:42.929961 25345 maintenance_manager.cc:643] P ed6f53a587794af0b54ab1fa07006aca: UndoDeltaBlockGCOp(e62d1537e9c94e87be8a3097d2e3dfa1) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":44,"lbm_reads_lt_1ms":4}
I20260812 06:16:42.930425 25435 maintenance_manager.cc:419] P ed6f53a587794af0b54ab1fa07006aca: Scheduling FlushDeltaMemStoresOp(e62d1537e9c94e87be8a3097d2e3dfa1): perf score=14.095187
I20260812 06:16:43.020594 25345 maintenance_manager.cc:643] P ed6f53a587794af0b54ab1fa07006aca: FlushDeltaMemStoresOp(e62d1537e9c94e87be8a3097d2e3dfa1) complete. Timing: real 0.090s	user 0.037s	sys 0.008s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":53993,"lbm_writes_10-100_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:16:43.021044 25435 maintenance_manager.cc:419] P ed6f53a587794af0b54ab1fa07006aca: Scheduling FlushDeltaMemStoresOp(e62d1537e9c94e87be8a3097d2e3dfa1): perf score=6.157687
I20260812 06:16:43.047580 25345 maintenance_manager.cc:643] P ed6f53a587794af0b54ab1fa07006aca: FlushDeltaMemStoresOp(e62d1537e9c94e87be8a3097d2e3dfa1) complete. Timing: real 0.026s	user 0.010s	sys 0.012s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":9904,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:16:43.048215 25435 maintenance_manager.cc:419] P ed6f53a587794af0b54ab1fa07006aca: Scheduling MajorDeltaCompactionOp(e62d1537e9c94e87be8a3097d2e3dfa1): perf score=1.000000
I20260812 06:16:43.202491 25345 maintenance_manager.cc:643] P ed6f53a587794af0b54ab1fa07006aca: MajorDeltaCompactionOp(e62d1537e9c94e87be8a3097d2e3dfa1) complete. Timing: real 0.154s	user 0.129s	sys 0.024s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877100,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1050,"lbm_read_time_us":10575,"lbm_reads_lt_1ms":664,"lbm_write_time_us":33507,"lbm_writes_lt_1ms":643,"mutex_wait_us":371,"peak_mem_usage":75542472,"reinsert_count":0,"update_count":3000}
I20260812 06:16:43.203049 25435 maintenance_manager.cc:419] P ed6f53a587794af0b54ab1fa07006aca: Scheduling FlushDeltaMemStoresOp(e62d1537e9c94e87be8a3097d2e3dfa1): perf score=14.095187
I20260812 06:16:43.253047 25345 maintenance_manager.cc:643] P ed6f53a587794af0b54ab1fa07006aca: FlushDeltaMemStoresOp(e62d1537e9c94e87be8a3097d2e3dfa1) complete. Timing: real 0.050s	user 0.043s	sys 0.004s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22099,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:43.253590 25435 maintenance_manager.cc:419] P ed6f53a587794af0b54ab1fa07006aca: Scheduling FlushDeltaMemStoresOp(e62d1537e9c94e87be8a3097d2e3dfa1): perf score=2.188937
I20260812 06:16:43.269606 25345 maintenance_manager.cc:643] P ed6f53a587794af0b54ab1fa07006aca: FlushDeltaMemStoresOp(e62d1537e9c94e87be8a3097d2e3dfa1) complete. Timing: real 0.016s	user 0.006s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6217,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:43.270080 25435 maintenance_manager.cc:419] P ed6f53a587794af0b54ab1fa07006aca: Scheduling MajorDeltaCompactionOp(e62d1537e9c94e87be8a3097d2e3dfa1): perf score=1.000000
I20260812 06:16:43.431012 25345 maintenance_manager.cc:643] P ed6f53a587794af0b54ab1fa07006aca: MajorDeltaCompactionOp(e62d1537e9c94e87be8a3097d2e3dfa1) complete. Timing: real 0.161s	user 0.132s	sys 0.024s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":271,"lbm_read_time_us":9100,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32276,"lbm_writes_lt_1ms":543,"mutex_wait_us":79,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:16:43.431959 25435 maintenance_manager.cc:419] P ed6f53a587794af0b54ab1fa07006aca: Scheduling FlushDeltaMemStoresOp(e62d1537e9c94e87be8a3097d2e3dfa1): perf score=12.110812
I20260812 06:16:43.476708 25345 maintenance_manager.cc:643] P ed6f53a587794af0b54ab1fa07006aca: FlushDeltaMemStoresOp(e62d1537e9c94e87be8a3097d2e3dfa1) complete. Timing: real 0.045s	user 0.033s	sys 0.010s Metrics: {"bytes_written":13579243,"delete_count":0,"lbm_write_time_us":17905,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":333,"reinsert_count":0,"update_count":1655}
I20260812 06:16:43.477427 25435 maintenance_manager.cc:419] P ed6f53a587794af0b54ab1fa07006aca: Scheduling FlushDeltaMemStoresOp(e62d1537e9c94e87be8a3097d2e3dfa1): perf score=1.196750
I20260812 06:16:43.496174 25345 maintenance_manager.cc:643] P ed6f53a587794af0b54ab1fa07006aca: FlushDeltaMemStoresOp(e62d1537e9c94e87be8a3097d2e3dfa1) complete. Timing: real 0.019s	user 0.006s	sys 0.004s Metrics: {"bytes_written":2830880,"delete_count":0,"lbm_write_time_us":4306,"lbm_writes_lt_1ms":72,"reinsert_count":0,"update_count":345}
I20260812 06:16:43.496803 25435 maintenance_manager.cc:419] P ed6f53a587794af0b54ab1fa07006aca: Scheduling FlushDeltaMemStoresOp(e62d1537e9c94e87be8a3097d2e3dfa1): perf score=2.188937
I20260812 06:16:43.509291 25345 maintenance_manager.cc:643] P ed6f53a587794af0b54ab1fa07006aca: FlushDeltaMemStoresOp(e62d1537e9c94e87be8a3097d2e3dfa1) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4881,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:43.509989 25435 maintenance_manager.cc:419] P ed6f53a587794af0b54ab1fa07006aca: Scheduling MajorDeltaCompactionOp(e62d1537e9c94e87be8a3097d2e3dfa1): perf score=1.000000
I20260812 06:16:43.691011 25345 maintenance_manager.cc:643] P ed6f53a587794af0b54ab1fa07006aca: MajorDeltaCompactionOp(e62d1537e9c94e87be8a3097d2e3dfa1) complete. Timing: real 0.181s	user 0.132s	sys 0.048s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774782,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":654,"lbm_read_time_us":14641,"lbm_reads_lt_1ms":573,"lbm_write_time_us":30664,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7808,"update_count":2500}
I20260812 06:16:43.691524 25435 maintenance_manager.cc:419] P ed6f53a587794af0b54ab1fa07006aca: Scheduling FlushDeltaMemStoresOp(e62d1537e9c94e87be8a3097d2e3dfa1): perf score=14.095187
I20260812 06:16:43.749362 25345 maintenance_manager.cc:643] P ed6f53a587794af0b54ab1fa07006aca: FlushDeltaMemStoresOp(e62d1537e9c94e87be8a3097d2e3dfa1) complete. Timing: real 0.058s	user 0.031s	sys 0.015s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21628,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:43.749904 25435 maintenance_manager.cc:419] P ed6f53a587794af0b54ab1fa07006aca: Scheduling FlushDeltaMemStoresOp(e62d1537e9c94e87be8a3097d2e3dfa1): perf score=2.188937
I20260812 06:16:43.760496 25345 maintenance_manager.cc:643] P ed6f53a587794af0b54ab1fa07006aca: FlushDeltaMemStoresOp(e62d1537e9c94e87be8a3097d2e3dfa1) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4078,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:43.760977 25435 maintenance_manager.cc:419] P ed6f53a587794af0b54ab1fa07006aca: Scheduling MajorDeltaCompactionOp(e62d1537e9c94e87be8a3097d2e3dfa1): perf score=1.000000
I20260812 06:16:43.944597 25345 maintenance_manager.cc:643] P ed6f53a587794af0b54ab1fa07006aca: MajorDeltaCompactionOp(e62d1537e9c94e87be8a3097d2e3dfa1) complete. Timing: real 0.183s	user 0.135s	sys 0.036s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":825,"lbm_read_time_us":13651,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30533,"lbm_writes_lt_1ms":543,"mutex_wait_us":275,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3968,"update_count":2500}
I20260812 06:16:43.945364 25435 maintenance_manager.cc:419] P ed6f53a587794af0b54ab1fa07006aca: Scheduling FlushDeltaMemStoresOp(e62d1537e9c94e87be8a3097d2e3dfa1): perf score=14.095187
I20260812 06:16:44.005311 25345 maintenance_manager.cc:643] P ed6f53a587794af0b54ab1fa07006aca: FlushDeltaMemStoresOp(e62d1537e9c94e87be8a3097d2e3dfa1) complete. Timing: real 0.060s	user 0.032s	sys 0.019s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19568,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:44.006050 25435 maintenance_manager.cc:419] P ed6f53a587794af0b54ab1fa07006aca: Scheduling FlushDeltaMemStoresOp(e62d1537e9c94e87be8a3097d2e3dfa1): perf score=2.188937
I20260812 06:16:44.022956 25345 maintenance_manager.cc:643] P ed6f53a587794af0b54ab1fa07006aca: FlushDeltaMemStoresOp(e62d1537e9c94e87be8a3097d2e3dfa1) complete. Timing: real 0.017s	user 0.003s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6410,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:44.023548 25435 maintenance_manager.cc:419] P ed6f53a587794af0b54ab1fa07006aca: Scheduling FlushMRSOp(e62d1537e9c94e87be8a3097d2e3dfa1): perf score=1.000000
I20260812 06:16:44.063215 25345 maintenance_manager.cc:643] P ed6f53a587794af0b54ab1fa07006aca: FlushMRSOp(e62d1537e9c94e87be8a3097d2e3dfa1) complete. Timing: real 0.039s	user 0.028s	sys 0.001s Metrics: {"bytes_written":1152514,"cfile_init":1,"dirs.queue_time_us":62,"dirs.run_cpu_time_us":202,"dirs.run_wall_time_us":1315,"drs_written":1,"lbm_read_time_us":42,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1492,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:16:44.064019 25435 maintenance_manager.cc:419] P ed6f53a587794af0b54ab1fa07006aca: Scheduling LogGCOp(e62d1537e9c94e87be8a3097d2e3dfa1): free 112239322 bytes of WAL
I20260812 06:16:44.064246 25345 log_reader.cc:385] T e62d1537e9c94e87be8a3097d2e3dfa1: removed 11 log segments from log reader
I20260812 06:16:44.064307 25345 log.cc:1079] T e62d1537e9c94e87be8a3097d2e3dfa1 P ed6f53a587794af0b54ab1fa07006aca: Deleting log segment in path: /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515400764805-25173-0/minicluster-data/ts-0-root/wals/e62d1537e9c94e87be8a3097d2e3dfa1/wal-000000015 (ops 72-76)
I20260812 06:16:44.064359 25345 log.cc:1079] T e62d1537e9c94e87be8a3097d2e3dfa1 P ed6f53a587794af0b54ab1fa07006aca: Deleting log segment in path: /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515400764805-25173-0/minicluster-data/ts-0-root/wals/e62d1537e9c94e87be8a3097d2e3dfa1/wal-000000016 (ops 77-81)
I20260812 06:16:44.064417 25345 log.cc:1079] T e62d1537e9c94e87be8a3097d2e3dfa1 P ed6f53a587794af0b54ab1fa07006aca: Deleting log segment in path: /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515400764805-25173-0/minicluster-data/ts-0-root/wals/e62d1537e9c94e87be8a3097d2e3dfa1/wal-000000017 (ops 82-86)
I20260812 06:16:44.064462 25345 log.cc:1079] T e62d1537e9c94e87be8a3097d2e3dfa1 P ed6f53a587794af0b54ab1fa07006aca: Deleting log segment in path: /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515400764805-25173-0/minicluster-data/ts-0-root/wals/e62d1537e9c94e87be8a3097d2e3dfa1/wal-000000018 (ops 87-91)
I20260812 06:16:44.064502 25345 log.cc:1079] T e62d1537e9c94e87be8a3097d2e3dfa1 P ed6f53a587794af0b54ab1fa07006aca: Deleting log segment in path: /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515400764805-25173-0/minicluster-data/ts-0-root/wals/e62d1537e9c94e87be8a3097d2e3dfa1/wal-000000019 (ops 92-96)
I20260812 06:16:44.064550 25345 log.cc:1079] T e62d1537e9c94e87be8a3097d2e3dfa1 P ed6f53a587794af0b54ab1fa07006aca: Deleting log segment in path: /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515400764805-25173-0/minicluster-data/ts-0-root/wals/e62d1537e9c94e87be8a3097d2e3dfa1/wal-000000020 (ops 97-101)
I20260812 06:16:44.064589 25345 log.cc:1079] T e62d1537e9c94e87be8a3097d2e3dfa1 P ed6f53a587794af0b54ab1fa07006aca: Deleting log segment in path: /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515400764805-25173-0/minicluster-data/ts-0-root/wals/e62d1537e9c94e87be8a3097d2e3dfa1/wal-000000021 (ops 102-106)
I20260812 06:16:44.064627 25345 log.cc:1079] T e62d1537e9c94e87be8a3097d2e3dfa1 P ed6f53a587794af0b54ab1fa07006aca: Deleting log segment in path: /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515400764805-25173-0/minicluster-data/ts-0-root/wals/e62d1537e9c94e87be8a3097d2e3dfa1/wal-000000022 (ops 107-111)
I20260812 06:16:44.064666 25345 log.cc:1079] T e62d1537e9c94e87be8a3097d2e3dfa1 P ed6f53a587794af0b54ab1fa07006aca: Deleting log segment in path: /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515400764805-25173-0/minicluster-data/ts-0-root/wals/e62d1537e9c94e87be8a3097d2e3dfa1/wal-000000023 (ops 112-116)
I20260812 06:16:44.064706 25345 log.cc:1079] T e62d1537e9c94e87be8a3097d2e3dfa1 P ed6f53a587794af0b54ab1fa07006aca: Deleting log segment in path: /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515400764805-25173-0/minicluster-data/ts-0-root/wals/e62d1537e9c94e87be8a3097d2e3dfa1/wal-000000024 (ops 117-120)
I20260812 06:16:44.064747 25345 log.cc:1079] T e62d1537e9c94e87be8a3097d2e3dfa1 P ed6f53a587794af0b54ab1fa07006aca: Deleting log segment in path: /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515400764805-25173-0/minicluster-data/ts-0-root/wals/e62d1537e9c94e87be8a3097d2e3dfa1/wal-000000025 (ops 121-125)
I20260812 06:16:44.090098 25345 maintenance_manager.cc:643] P ed6f53a587794af0b54ab1fa07006aca: LogGCOp(e62d1537e9c94e87be8a3097d2e3dfa1) complete. Timing: real 0.026s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:16:44.090476 25435 maintenance_manager.cc:419] P ed6f53a587794af0b54ab1fa07006aca: Scheduling UndoDeltaBlockGCOp(e62d1537e9c94e87be8a3097d2e3dfa1): 447 bytes on disk
I20260812 06:16:44.090936 25345 maintenance_manager.cc:643] P ed6f53a587794af0b54ab1fa07006aca: UndoDeltaBlockGCOp(e62d1537e9c94e87be8a3097d2e3dfa1) 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:16:44.091791 25435 maintenance_manager.cc:419] P ed6f53a587794af0b54ab1fa07006aca: Scheduling FlushDeltaMemStoresOp(e62d1537e9c94e87be8a3097d2e3dfa1): perf score=2.188937
I20260812 06:16:44.111779 25345 maintenance_manager.cc:643] P ed6f53a587794af0b54ab1fa07006aca: FlushDeltaMemStoresOp(e62d1537e9c94e87be8a3097d2e3dfa1) complete. Timing: real 0.020s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4376,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:44.112286 25435 maintenance_manager.cc:419] P ed6f53a587794af0b54ab1fa07006aca: Scheduling FlushDeltaMemStoresOp(e62d1537e9c94e87be8a3097d2e3dfa1): perf score=2.188937
I20260812 06:16:44.123137 25345 maintenance_manager.cc:643] P ed6f53a587794af0b54ab1fa07006aca: FlushDeltaMemStoresOp(e62d1537e9c94e87be8a3097d2e3dfa1) complete. Timing: real 0.011s	user 0.003s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3973,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:44.123664 25435 maintenance_manager.cc:419] P ed6f53a587794af0b54ab1fa07006aca: Scheduling MajorDeltaCompactionOp(e62d1537e9c94e87be8a3097d2e3dfa1): perf score=1.000000
I20260812 06:16:44.354488 25345 maintenance_manager.cc:643] P ed6f53a587794af0b54ab1fa07006aca: MajorDeltaCompactionOp(e62d1537e9c94e87be8a3097d2e3dfa1) complete. Timing: real 0.231s	user 0.159s	sys 0.060s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979750,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":964,"lbm_read_time_us":14307,"lbm_reads_lt_1ms":774,"lbm_write_time_us":41832,"lbm_writes_lt_1ms":743,"mutex_wait_us":45,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":20608,"thread_start_us":99,"threads_started":1,"update_count":3500}
I20260812 06:16:44.355741 25435 maintenance_manager.cc:419] P ed6f53a587794af0b54ab1fa07006aca: Scheduling FlushDeltaMemStoresOp(e62d1537e9c94e87be8a3097d2e3dfa1): perf score=18.063937
I20260812 06:16:44.418849 25345 maintenance_manager.cc:643] P ed6f53a587794af0b54ab1fa07006aca: FlushDeltaMemStoresOp(e62d1537e9c94e87be8a3097d2e3dfa1) complete. Timing: real 0.063s	user 0.040s	sys 0.017s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":29731,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":502,"reinsert_count":0,"update_count":2500}
I20260812 06:16:44.419471 25435 maintenance_manager.cc:419] P ed6f53a587794af0b54ab1fa07006aca: Scheduling FlushDeltaMemStoresOp(e62d1537e9c94e87be8a3097d2e3dfa1): perf score=2.188937
I20260812 06:16:44.434448 25345 maintenance_manager.cc:643] P ed6f53a587794af0b54ab1fa07006aca: FlushDeltaMemStoresOp(e62d1537e9c94e87be8a3097d2e3dfa1) complete. Timing: real 0.015s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5416,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:44.434926 25435 maintenance_manager.cc:419] P ed6f53a587794af0b54ab1fa07006aca: Scheduling MajorDeltaCompactionOp(e62d1537e9c94e87be8a3097d2e3dfa1): perf score=1.000000
I20260812 06:16:44.607230 25345 maintenance_manager.cc:643] P ed6f53a587794af0b54ab1fa07006aca: MajorDeltaCompactionOp(e62d1537e9c94e87be8a3097d2e3dfa1) complete. Timing: real 0.172s	user 0.139s	sys 0.032s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877101,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1528,"lbm_read_time_us":12474,"lbm_reads_lt_1ms":672,"lbm_write_time_us":34390,"lbm_writes_lt_1ms":643,"mutex_wait_us":586,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":9344,"update_count":3000}
I20260812 06:16:44.608103 25435 maintenance_manager.cc:419] P ed6f53a587794af0b54ab1fa07006aca: Scheduling FlushDeltaMemStoresOp(e62d1537e9c94e87be8a3097d2e3dfa1): perf score=14.095187
I20260812 06:16:44.664125 25345 maintenance_manager.cc:643] P ed6f53a587794af0b54ab1fa07006aca: FlushDeltaMemStoresOp(e62d1537e9c94e87be8a3097d2e3dfa1) complete. Timing: real 0.056s	user 0.027s	sys 0.028s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23960,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:44.664614 25435 maintenance_manager.cc:419] P ed6f53a587794af0b54ab1fa07006aca: Scheduling FlushDeltaMemStoresOp(e62d1537e9c94e87be8a3097d2e3dfa1): perf score=3.181125
I20260812 06:16:44.682376 25345 maintenance_manager.cc:643] P ed6f53a587794af0b54ab1fa07006aca: FlushDeltaMemStoresOp(e62d1537e9c94e87be8a3097d2e3dfa1) complete. Timing: real 0.018s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4496,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:16:44.682828 25435 maintenance_manager.cc:419] P ed6f53a587794af0b54ab1fa07006aca: Scheduling FlushDeltaMemStoresOp(e62d1537e9c94e87be8a3097d2e3dfa1): perf score=2.188937
I20260812 06:16:44.693598 25345 maintenance_manager.cc:643] P ed6f53a587794af0b54ab1fa07006aca: FlushDeltaMemStoresOp(e62d1537e9c94e87be8a3097d2e3dfa1) complete. Timing: real 0.011s	user 0.002s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4037,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:44.694056 25435 maintenance_manager.cc:419] P ed6f53a587794af0b54ab1fa07006aca: Scheduling MajorDeltaCompactionOp(e62d1537e9c94e87be8a3097d2e3dfa1): perf score=1.000000
I20260812 06:16:44.864301 25345 maintenance_manager.cc:643] P ed6f53a587794af0b54ab1fa07006aca: MajorDeltaCompactionOp(e62d1537e9c94e87be8a3097d2e3dfa1) complete. Timing: real 0.170s	user 0.142s	sys 0.024s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877210,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1212,"lbm_read_time_us":12243,"lbm_reads_lt_1ms":673,"lbm_write_time_us":38240,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":642,"mutex_wait_us":274,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":4992,"update_count":3000}
I20260812 06:16:44.865051 25435 maintenance_manager.cc:419] P ed6f53a587794af0b54ab1fa07006aca: Scheduling FlushDeltaMemStoresOp(e62d1537e9c94e87be8a3097d2e3dfa1): perf score=14.095187
I20260812 06:16:44.921202 25345 maintenance_manager.cc:643] P ed6f53a587794af0b54ab1fa07006aca: FlushDeltaMemStoresOp(e62d1537e9c94e87be8a3097d2e3dfa1) complete. Timing: real 0.056s	user 0.029s	sys 0.023s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23199,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:44.921864 25435 maintenance_manager.cc:419] P ed6f53a587794af0b54ab1fa07006aca: Scheduling FlushDeltaMemStoresOp(e62d1537e9c94e87be8a3097d2e3dfa1): perf score=2.188937
I20260812 06:16:44.942094 25345 maintenance_manager.cc:643] P ed6f53a587794af0b54ab1fa07006aca: FlushDeltaMemStoresOp(e62d1537e9c94e87be8a3097d2e3dfa1) complete. Timing: real 0.020s	user 0.011s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6823,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:44.942693 25435 maintenance_manager.cc:419] P ed6f53a587794af0b54ab1fa07006aca: Scheduling MajorDeltaCompactionOp(e62d1537e9c94e87be8a3097d2e3dfa1): perf score=1.000000
I20260812 06:16:45.095434 25345 maintenance_manager.cc:643] P ed6f53a587794af0b54ab1fa07006aca: MajorDeltaCompactionOp(e62d1537e9c94e87be8a3097d2e3dfa1) complete. Timing: real 0.153s	user 0.112s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1055,"lbm_read_time_us":8614,"lbm_reads_lt_1ms":564,"lbm_write_time_us":30524,"lbm_writes_lt_1ms":543,"mutex_wait_us":23,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11392,"update_count":2500}
I20260812 06:16:45.096038 25435 maintenance_manager.cc:419] P ed6f53a587794af0b54ab1fa07006aca: Scheduling FlushDeltaMemStoresOp(e62d1537e9c94e87be8a3097d2e3dfa1): perf score=14.095187
I20260812 06:16:45.159332 25345 maintenance_manager.cc:643] P ed6f53a587794af0b54ab1fa07006aca: FlushDeltaMemStoresOp(e62d1537e9c94e87be8a3097d2e3dfa1) complete. Timing: real 0.063s	user 0.042s	sys 0.009s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24038,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:16:45.159915 25435 maintenance_manager.cc:419] P ed6f53a587794af0b54ab1fa07006aca: Scheduling FlushDeltaMemStoresOp(e62d1537e9c94e87be8a3097d2e3dfa1): perf score=2.188937
I20260812 06:16:45.170589 25345 maintenance_manager.cc:643] P ed6f53a587794af0b54ab1fa07006aca: FlushDeltaMemStoresOp(e62d1537e9c94e87be8a3097d2e3dfa1) complete. Timing: real 0.010s	user 0.001s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4138,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:45.171057 25435 maintenance_manager.cc:419] P ed6f53a587794af0b54ab1fa07006aca: Scheduling MajorDeltaCompactionOp(e62d1537e9c94e87be8a3097d2e3dfa1): perf score=1.000000
I20260812 06:16:45.338419 25345 maintenance_manager.cc:643] P ed6f53a587794af0b54ab1fa07006aca: MajorDeltaCompactionOp(e62d1537e9c94e87be8a3097d2e3dfa1) complete. Timing: real 0.167s	user 0.122s	sys 0.045s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":166,"lbm_read_time_us":12653,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28351,"lbm_writes_lt_1ms":543,"mutex_wait_us":38,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2048,"update_count":2500}
I20260812 06:16:45.339146 25435 maintenance_manager.cc:419] P ed6f53a587794af0b54ab1fa07006aca: Scheduling FlushDeltaMemStoresOp(e62d1537e9c94e87be8a3097d2e3dfa1): perf score=14.095187
I20260812 06:16:45.403136 25345 maintenance_manager.cc:643] P ed6f53a587794af0b54ab1fa07006aca: FlushDeltaMemStoresOp(e62d1537e9c94e87be8a3097d2e3dfa1) complete. Timing: real 0.064s	user 0.028s	sys 0.025s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":23317,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:45.403618 25435 maintenance_manager.cc:419] P ed6f53a587794af0b54ab1fa07006aca: Scheduling FlushDeltaMemStoresOp(e62d1537e9c94e87be8a3097d2e3dfa1): perf score=2.188937
I20260812 06:16:45.415169 25345 maintenance_manager.cc:643] P ed6f53a587794af0b54ab1fa07006aca: FlushDeltaMemStoresOp(e62d1537e9c94e87be8a3097d2e3dfa1) complete. Timing: real 0.011s	user 0.011s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4028,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:45.415805 25435 maintenance_manager.cc:419] P ed6f53a587794af0b54ab1fa07006aca: Scheduling FlushMRSOp(e62d1537e9c94e87be8a3097d2e3dfa1): perf score=1.000000
I20260812 06:16:45.447549 25345 maintenance_manager.cc:643] P ed6f53a587794af0b54ab1fa07006aca: FlushMRSOp(e62d1537e9c94e87be8a3097d2e3dfa1) complete. Timing: real 0.032s	user 0.031s	sys 0.000s Metrics: {"bytes_written":1193505,"cfile_init":1,"dirs.queue_time_us":61,"dirs.run_cpu_time_us":189,"dirs.run_wall_time_us":1297,"drs_written":1,"lbm_read_time_us":44,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1785,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29,"spinlock_wait_cycles":28800}
I20260812 06:16:45.448273 25435 maintenance_manager.cc:419] P ed6f53a587794af0b54ab1fa07006aca: Scheduling LogGCOp(e62d1537e9c94e87be8a3097d2e3dfa1): free 120100619 bytes of WAL
I20260812 06:16:45.448596 25345 log_reader.cc:385] T e62d1537e9c94e87be8a3097d2e3dfa1: removed 12 log segments from log reader
I20260812 06:16:45.448673 25345 log.cc:1079] T e62d1537e9c94e87be8a3097d2e3dfa1 P ed6f53a587794af0b54ab1fa07006aca: Deleting log segment in path: /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515400764805-25173-0/minicluster-data/ts-0-root/wals/e62d1537e9c94e87be8a3097d2e3dfa1/wal-000000026 (ops 126-130)
I20260812 06:16:45.448725 25345 log.cc:1079] T e62d1537e9c94e87be8a3097d2e3dfa1 P ed6f53a587794af0b54ab1fa07006aca: Deleting log segment in path: /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515400764805-25173-0/minicluster-data/ts-0-root/wals/e62d1537e9c94e87be8a3097d2e3dfa1/wal-000000027 (ops 131-135)
I20260812 06:16:45.448794 25345 log.cc:1079] T e62d1537e9c94e87be8a3097d2e3dfa1 P ed6f53a587794af0b54ab1fa07006aca: Deleting log segment in path: /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515400764805-25173-0/minicluster-data/ts-0-root/wals/e62d1537e9c94e87be8a3097d2e3dfa1/wal-000000028 (ops 136-140)
I20260812 06:16:45.448836 25345 log.cc:1079] T e62d1537e9c94e87be8a3097d2e3dfa1 P ed6f53a587794af0b54ab1fa07006aca: Deleting log segment in path: /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515400764805-25173-0/minicluster-data/ts-0-root/wals/e62d1537e9c94e87be8a3097d2e3dfa1/wal-000000029 (ops 141-144)
I20260812 06:16:45.448872 25345 log.cc:1079] T e62d1537e9c94e87be8a3097d2e3dfa1 P ed6f53a587794af0b54ab1fa07006aca: Deleting log segment in path: /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515400764805-25173-0/minicluster-data/ts-0-root/wals/e62d1537e9c94e87be8a3097d2e3dfa1/wal-000000030 (ops 145-149)
I20260812 06:16:45.448908 25345 log.cc:1079] T e62d1537e9c94e87be8a3097d2e3dfa1 P ed6f53a587794af0b54ab1fa07006aca: Deleting log segment in path: /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515400764805-25173-0/minicluster-data/ts-0-root/wals/e62d1537e9c94e87be8a3097d2e3dfa1/wal-000000031 (ops 150-154)
I20260812 06:16:45.448944 25345 log.cc:1079] T e62d1537e9c94e87be8a3097d2e3dfa1 P ed6f53a587794af0b54ab1fa07006aca: Deleting log segment in path: /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515400764805-25173-0/minicluster-data/ts-0-root/wals/e62d1537e9c94e87be8a3097d2e3dfa1/wal-000000032 (ops 155-158)
I20260812 06:16:45.448980 25345 log.cc:1079] T e62d1537e9c94e87be8a3097d2e3dfa1 P ed6f53a587794af0b54ab1fa07006aca: Deleting log segment in path: /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515400764805-25173-0/minicluster-data/ts-0-root/wals/e62d1537e9c94e87be8a3097d2e3dfa1/wal-000000033 (ops 159-163)
I20260812 06:16:45.449016 25345 log.cc:1079] T e62d1537e9c94e87be8a3097d2e3dfa1 P ed6f53a587794af0b54ab1fa07006aca: Deleting log segment in path: /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515400764805-25173-0/minicluster-data/ts-0-root/wals/e62d1537e9c94e87be8a3097d2e3dfa1/wal-000000034 (ops 164-168)
I20260812 06:16:45.449054 25345 log.cc:1079] T e62d1537e9c94e87be8a3097d2e3dfa1 P ed6f53a587794af0b54ab1fa07006aca: Deleting log segment in path: /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515400764805-25173-0/minicluster-data/ts-0-root/wals/e62d1537e9c94e87be8a3097d2e3dfa1/wal-000000035 (ops 169-172)
I20260812 06:16:45.449090 25345 log.cc:1079] T e62d1537e9c94e87be8a3097d2e3dfa1 P ed6f53a587794af0b54ab1fa07006aca: Deleting log segment in path: /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515400764805-25173-0/minicluster-data/ts-0-root/wals/e62d1537e9c94e87be8a3097d2e3dfa1/wal-000000036 (ops 173-177)
I20260812 06:16:45.449127 25345 log.cc:1079] T e62d1537e9c94e87be8a3097d2e3dfa1 P ed6f53a587794af0b54ab1fa07006aca: Deleting log segment in path: /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515400764805-25173-0/minicluster-data/ts-0-root/wals/e62d1537e9c94e87be8a3097d2e3dfa1/wal-000000037 (ops 178-182)
I20260812 06:16:45.475579 25345 maintenance_manager.cc:643] P ed6f53a587794af0b54ab1fa07006aca: LogGCOp(e62d1537e9c94e87be8a3097d2e3dfa1) complete. Timing: real 0.027s	user 0.003s	sys 0.023s Metrics: {}
I20260812 06:16:45.476810 25435 maintenance_manager.cc:419] P ed6f53a587794af0b54ab1fa07006aca: Scheduling UndoDeltaBlockGCOp(e62d1537e9c94e87be8a3097d2e3dfa1): 462 bytes on disk
I20260812 06:16:45.479658 25345 maintenance_manager.cc:643] P ed6f53a587794af0b54ab1fa07006aca: UndoDeltaBlockGCOp(e62d1537e9c94e87be8a3097d2e3dfa1) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":75,"lbm_reads_lt_1ms":4}
I20260812 06:16:45.480261 25435 maintenance_manager.cc:419] P ed6f53a587794af0b54ab1fa07006aca: Scheduling FlushDeltaMemStoresOp(e62d1537e9c94e87be8a3097d2e3dfa1): perf score=3.181125
I20260812 06:16:45.499315 25345 maintenance_manager.cc:643] P ed6f53a587794af0b54ab1fa07006aca: FlushDeltaMemStoresOp(e62d1537e9c94e87be8a3097d2e3dfa1) complete. Timing: real 0.019s	user 0.010s	sys 0.008s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":6976,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:16:45.499773 25435 maintenance_manager.cc:419] P ed6f53a587794af0b54ab1fa07006aca: Scheduling FlushDeltaMemStoresOp(e62d1537e9c94e87be8a3097d2e3dfa1): perf score=2.188937
I20260812 06:16:45.510789 25345 maintenance_manager.cc:643] P ed6f53a587794af0b54ab1fa07006aca: FlushDeltaMemStoresOp(e62d1537e9c94e87be8a3097d2e3dfa1) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4240,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:45.511296 25435 maintenance_manager.cc:419] P ed6f53a587794af0b54ab1fa07006aca: Scheduling MajorDeltaCompactionOp(e62d1537e9c94e87be8a3097d2e3dfa1): perf score=1.000000
I20260812 06:16:45.739534 25345 maintenance_manager.cc:643] P ed6f53a587794af0b54ab1fa07006aca: MajorDeltaCompactionOp(e62d1537e9c94e87be8a3097d2e3dfa1) complete. Timing: real 0.228s	user 0.160s	sys 0.056s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979741,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":724,"lbm_read_time_us":15369,"lbm_reads_lt_1ms":774,"lbm_write_time_us":40212,"lbm_writes_lt_1ms":743,"mutex_wait_us":275,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":4224,"thread_start_us":88,"threads_started":1,"update_count":3500}
I20260812 06:16:45.740110 25435 maintenance_manager.cc:419] P ed6f53a587794af0b54ab1fa07006aca: Scheduling FlushDeltaMemStoresOp(e62d1537e9c94e87be8a3097d2e3dfa1): perf score=18.063937
I20260812 06:16:45.793289 25345 maintenance_manager.cc:643] P ed6f53a587794af0b54ab1fa07006aca: FlushDeltaMemStoresOp(e62d1537e9c94e87be8a3097d2e3dfa1) complete. Timing: real 0.053s	user 0.031s	sys 0.020s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":23692,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:16:45.793820 25435 maintenance_manager.cc:419] P ed6f53a587794af0b54ab1fa07006aca: Scheduling FlushDeltaMemStoresOp(e62d1537e9c94e87be8a3097d2e3dfa1): perf score=2.188937
I20260812 06:16:45.809672 25345 maintenance_manager.cc:643] P ed6f53a587794af0b54ab1fa07006aca: FlushDeltaMemStoresOp(e62d1537e9c94e87be8a3097d2e3dfa1) complete. Timing: real 0.016s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6043,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:45.810303 25435 maintenance_manager.cc:419] P ed6f53a587794af0b54ab1fa07006aca: Scheduling MajorDeltaCompactionOp(e62d1537e9c94e87be8a3097d2e3dfa1): perf score=1.000000
I20260812 06:16:45.826987 25173 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.778s	user 1.792s	sys 0.151s
I20260812 06:16:45.882078 25173 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.054s	user 0.001s	sys 0.000s
I20260812 06:16:45.882656 25173 tablet_server.cc:179] TabletServer@127.24.149.65:0 shutting down...
I20260812 06:16:45.956496 25345 maintenance_manager.cc:643] P ed6f53a587794af0b54ab1fa07006aca: MajorDeltaCompactionOp(e62d1537e9c94e87be8a3097d2e3dfa1) complete. Timing: real 0.146s	user 0.118s	sys 0.027s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877103,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":716,"lbm_read_time_us":10454,"lbm_reads_lt_1ms":668,"lbm_write_time_us":29611,"lbm_writes_lt_1ms":643,"mutex_wait_us":305,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":44416,"update_count":3000}
I20260812 06:16:45.957276 25173 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:16:45.957721 25173 tablet_replica.cc:333] T e62d1537e9c94e87be8a3097d2e3dfa1 P ed6f53a587794af0b54ab1fa07006aca: stopping tablet replica
I20260812 06:16:45.957978 25173 raft_consensus.cc:2243] T e62d1537e9c94e87be8a3097d2e3dfa1 P ed6f53a587794af0b54ab1fa07006aca [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:45.958247 25173 raft_consensus.cc:2272] T e62d1537e9c94e87be8a3097d2e3dfa1 P ed6f53a587794af0b54ab1fa07006aca [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:45.976498 25173 tablet_server.cc:196] TabletServer@127.24.149.65:0 shutdown complete.
I20260812 06:16:46.010406 25173 master.cc:562] Master@127.24.149.126:44953 shutting down...
I20260812 06:16:46.014468 25173 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 7281e9723abe41aaa5ad9122f86df63a [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:46.014670 25173 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 7281e9723abe41aaa5ad9122f86df63a [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:46.014770 25173 tablet_replica.cc:333] T 00000000000000000000000000000000 P 7281e9723abe41aaa5ad9122f86df63a: stopping tablet replica
I20260812 06:16:46.027339 25173 master.cc:584] Master@127.24.149.126:44953 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5343 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:16:46.118228 25173 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.24.149.126:40159
I20260812 06:16:46.118587 25173 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:46.120674 25492 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:16:46.120674 25491 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:16:46.120795 25173 server_base.cc:1061] running on GCE node
W20260812 06:16:46.120781 25496 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:16:46.121135 25173 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:46.121179 25173 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:16:46.121232 25173 hybrid_clock.cc:648] HybridClock initialized: now 1786515406121231 us; error 0 us; skew 500 ppm
I20260812 06:16:46.122092 25173 webserver.cc:533] Webserver started at http://127.24.149.126:34645/ using document root <none> and password file <none>
I20260812 06:16:46.122272 25173 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:46.122323 25173 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:46.122404 25173 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:46.122788 25173 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515400764805-25173-0/minicluster-data/master-0-root/instance:
uuid: "251f5a7a16fe44acb147a3365f0f5d6d"
format_stamp: "Formatted at 2026-08-12 06:16:46 on dist-test-slave-n326"
I20260812 06:16:46.124385 25173 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:16:46.125314 25504 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:16:46.125552 25173 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:16:46.125646 25173 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515400764805-25173-0/minicluster-data/master-0-root
uuid: "251f5a7a16fe44acb147a3365f0f5d6d"
format_stamp: "Formatted at 2026-08-12 06:16:46 on dist-test-slave-n326"
I20260812 06:16:46.125734 25173 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515400764805-25173-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515400764805-25173-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515400764805-25173-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:16:46.136844 25173 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:46.137283 25173 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:46.141793 25173 rpc_server.cc:307] RPC server started. Bound to: 127.24.149.126:40159
I20260812 06:16:46.149816 25587 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:16:46.152503 25585 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.24.149.126:40159 every 8 connection(s)
I20260812 06:16:46.155026 25587 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 251f5a7a16fe44acb147a3365f0f5d6d: Bootstrap starting.
I20260812 06:16:46.155841 25587 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 251f5a7a16fe44acb147a3365f0f5d6d: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:46.156853 25587 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 251f5a7a16fe44acb147a3365f0f5d6d: No bootstrap required, opened a new log
I20260812 06:16:46.157261 25587 raft_consensus.cc:359] T 00000000000000000000000000000000 P 251f5a7a16fe44acb147a3365f0f5d6d [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "251f5a7a16fe44acb147a3365f0f5d6d" member_type: VOTER }
I20260812 06:16:46.157371 25587 raft_consensus.cc:385] T 00000000000000000000000000000000 P 251f5a7a16fe44acb147a3365f0f5d6d [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:46.157438 25587 raft_consensus.cc:740] T 00000000000000000000000000000000 P 251f5a7a16fe44acb147a3365f0f5d6d [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 251f5a7a16fe44acb147a3365f0f5d6d, State: Initialized, Role: FOLLOWER
I20260812 06:16:46.157612 25587 consensus_queue.cc:260] T 00000000000000000000000000000000 P 251f5a7a16fe44acb147a3365f0f5d6d [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: "251f5a7a16fe44acb147a3365f0f5d6d" member_type: VOTER }
I20260812 06:16:46.157706 25587 raft_consensus.cc:399] T 00000000000000000000000000000000 P 251f5a7a16fe44acb147a3365f0f5d6d [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:46.157749 25587 raft_consensus.cc:493] T 00000000000000000000000000000000 P 251f5a7a16fe44acb147a3365f0f5d6d [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:46.157804 25587 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 251f5a7a16fe44acb147a3365f0f5d6d [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:46.158468 25587 raft_consensus.cc:515] T 00000000000000000000000000000000 P 251f5a7a16fe44acb147a3365f0f5d6d [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "251f5a7a16fe44acb147a3365f0f5d6d" member_type: VOTER }
I20260812 06:16:46.158624 25587 leader_election.cc:304] T 00000000000000000000000000000000 P 251f5a7a16fe44acb147a3365f0f5d6d [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: 251f5a7a16fe44acb147a3365f0f5d6d; no voters: 
I20260812 06:16:46.158825 25587 leader_election.cc:290] T 00000000000000000000000000000000 P 251f5a7a16fe44acb147a3365f0f5d6d [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:46.158926 25592 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 251f5a7a16fe44acb147a3365f0f5d6d [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:46.159222 25592 raft_consensus.cc:697] T 00000000000000000000000000000000 P 251f5a7a16fe44acb147a3365f0f5d6d [term 1 LEADER]: Becoming Leader. State: Replica: 251f5a7a16fe44acb147a3365f0f5d6d, State: Running, Role: LEADER
I20260812 06:16:46.159337 25587 sys_catalog.cc:565] T 00000000000000000000000000000000 P 251f5a7a16fe44acb147a3365f0f5d6d [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:16:46.159384 25592 consensus_queue.cc:237] T 00000000000000000000000000000000 P 251f5a7a16fe44acb147a3365f0f5d6d [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: "251f5a7a16fe44acb147a3365f0f5d6d" member_type: VOTER }
I20260812 06:16:46.159822 25593 sys_catalog.cc:455] T 00000000000000000000000000000000 P 251f5a7a16fe44acb147a3365f0f5d6d [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "251f5a7a16fe44acb147a3365f0f5d6d" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "251f5a7a16fe44acb147a3365f0f5d6d" member_type: VOTER } }
I20260812 06:16:46.159934 25593 sys_catalog.cc:458] T 00000000000000000000000000000000 P 251f5a7a16fe44acb147a3365f0f5d6d [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:46.159835 25596 sys_catalog.cc:455] T 00000000000000000000000000000000 P 251f5a7a16fe44acb147a3365f0f5d6d [sys.catalog]: SysCatalogTable state changed. Reason: New leader 251f5a7a16fe44acb147a3365f0f5d6d. Latest consensus state: current_term: 1 leader_uuid: "251f5a7a16fe44acb147a3365f0f5d6d" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "251f5a7a16fe44acb147a3365f0f5d6d" member_type: VOTER } }
I20260812 06:16:46.160000 25596 sys_catalog.cc:458] T 00000000000000000000000000000000 P 251f5a7a16fe44acb147a3365f0f5d6d [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:46.160274 25610 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:16:46.161019 25610 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:16:46.161393 25173 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:16:46.162781 25610 catalog_manager.cc:1383] Generated new cluster ID: 57cbe2d7e5484219ba27da4b4c87df85
I20260812 06:16:46.162837 25610 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:16:46.192405 25610 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:16:46.192953 25610 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:16:46.201282 25610 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 251f5a7a16fe44acb147a3365f0f5d6d: Generated new TSK 0
I20260812 06:16:46.201470 25610 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:16:46.225927 25173 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:46.227969 25629 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:16:46.228075 25633 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:16:46.228250 25173 server_base.cc:1061] running on GCE node
W20260812 06:16:46.228080 25631 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:16:46.228528 25173 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:46.228590 25173 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:16:46.228624 25173 hybrid_clock.cc:648] HybridClock initialized: now 1786515406228623 us; error 0 us; skew 500 ppm
I20260812 06:16:46.229581 25173 webserver.cc:533] Webserver started at http://127.24.149.65:36265/ using document root <none> and password file <none>
I20260812 06:16:46.229775 25173 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:46.229853 25173 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:46.229944 25173 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:46.230436 25173 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515400764805-25173-0/minicluster-data/ts-0-root/instance:
uuid: "6655e200ad2a4580a61edb24e18b8258"
format_stamp: "Formatted at 2026-08-12 06:16:46 on dist-test-slave-n326"
I20260812 06:16:46.232429 25173 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.000s	sys 0.003s
I20260812 06:16:46.233520 25641 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:16:46.233790 25173 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:16:46.233883 25173 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515400764805-25173-0/minicluster-data/ts-0-root
uuid: "6655e200ad2a4580a61edb24e18b8258"
format_stamp: "Formatted at 2026-08-12 06:16:46 on dist-test-slave-n326"
I20260812 06:16:46.233976 25173 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515400764805-25173-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515400764805-25173-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515400764805-25173-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:16:46.244731 25173 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:46.245110 25173 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:46.245426 25173 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:16:46.245894 25173 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:16:46.245956 25173 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:46.246017 25173 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:16:46.246050 25173 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:46.250658 25173 rpc_server.cc:307] RPC server started. Bound to: 127.24.149.65:46621
I20260812 06:16:46.250841 25746 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.24.149.65:46621 every 8 connection(s)
I20260812 06:16:46.259759 25750 heartbeater.cc:344] Connected to a master server at 127.24.149.126:40159
I20260812 06:16:46.259878 25750 heartbeater.cc:461] Registering TS with master...
I20260812 06:16:46.260138 25750 heartbeater.cc:507] Master 127.24.149.126:40159 requested a full tablet report, sending...
I20260812 06:16:46.260793 25531 ts_manager.cc:194] Registered new tserver with Master: 6655e200ad2a4580a61edb24e18b8258 (127.24.149.65:46621)
I20260812 06:16:46.261225 25173 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.009989155s
I20260812 06:16:46.261690 25531 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:50720
I20260812 06:16:46.268713 25531 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:50736:
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:16:46.277789 25686 tablet_service.cc:1511] Processing CreateTablet for tablet 4bae55ff194f4d83acdc68cae6fb694f (DEFAULT_TABLE table=heavy-update-compaction-test [id=3d0ae5b3c4614b9da5b7855c0ad5b40a]), partition=
I20260812 06:16:46.278050 25686 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 4bae55ff194f4d83acdc68cae6fb694f. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:16:46.280285 25769 tablet_bootstrap.cc:492] T 4bae55ff194f4d83acdc68cae6fb694f P 6655e200ad2a4580a61edb24e18b8258: Bootstrap starting.
I20260812 06:16:46.281204 25769 tablet_bootstrap.cc:654] T 4bae55ff194f4d83acdc68cae6fb694f P 6655e200ad2a4580a61edb24e18b8258: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:46.282414 25769 tablet_bootstrap.cc:492] T 4bae55ff194f4d83acdc68cae6fb694f P 6655e200ad2a4580a61edb24e18b8258: No bootstrap required, opened a new log
I20260812 06:16:46.282529 25769 ts_tablet_manager.cc:1403] T 4bae55ff194f4d83acdc68cae6fb694f P 6655e200ad2a4580a61edb24e18b8258: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:16:46.283123 25769 raft_consensus.cc:359] T 4bae55ff194f4d83acdc68cae6fb694f P 6655e200ad2a4580a61edb24e18b8258 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6655e200ad2a4580a61edb24e18b8258" member_type: VOTER last_known_addr { host: "127.24.149.65" port: 46621 } }
I20260812 06:16:46.283254 25769 raft_consensus.cc:385] T 4bae55ff194f4d83acdc68cae6fb694f P 6655e200ad2a4580a61edb24e18b8258 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:46.283305 25769 raft_consensus.cc:740] T 4bae55ff194f4d83acdc68cae6fb694f P 6655e200ad2a4580a61edb24e18b8258 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 6655e200ad2a4580a61edb24e18b8258, State: Initialized, Role: FOLLOWER
I20260812 06:16:46.283457 25769 consensus_queue.cc:260] T 4bae55ff194f4d83acdc68cae6fb694f P 6655e200ad2a4580a61edb24e18b8258 [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: "6655e200ad2a4580a61edb24e18b8258" member_type: VOTER last_known_addr { host: "127.24.149.65" port: 46621 } }
I20260812 06:16:46.283572 25769 raft_consensus.cc:399] T 4bae55ff194f4d83acdc68cae6fb694f P 6655e200ad2a4580a61edb24e18b8258 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:46.283622 25769 raft_consensus.cc:493] T 4bae55ff194f4d83acdc68cae6fb694f P 6655e200ad2a4580a61edb24e18b8258 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:46.283676 25769 raft_consensus.cc:3060] T 4bae55ff194f4d83acdc68cae6fb694f P 6655e200ad2a4580a61edb24e18b8258 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:46.284498 25769 raft_consensus.cc:515] T 4bae55ff194f4d83acdc68cae6fb694f P 6655e200ad2a4580a61edb24e18b8258 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6655e200ad2a4580a61edb24e18b8258" member_type: VOTER last_known_addr { host: "127.24.149.65" port: 46621 } }
I20260812 06:16:46.284663 25769 leader_election.cc:304] T 4bae55ff194f4d83acdc68cae6fb694f P 6655e200ad2a4580a61edb24e18b8258 [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: 6655e200ad2a4580a61edb24e18b8258; no voters: 
I20260812 06:16:46.284907 25769 leader_election.cc:290] T 4bae55ff194f4d83acdc68cae6fb694f P 6655e200ad2a4580a61edb24e18b8258 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:46.285027 25772 raft_consensus.cc:2804] T 4bae55ff194f4d83acdc68cae6fb694f P 6655e200ad2a4580a61edb24e18b8258 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:46.285368 25769 ts_tablet_manager.cc:1434] T 4bae55ff194f4d83acdc68cae6fb694f P 6655e200ad2a4580a61edb24e18b8258: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:16:46.285343 25750 heartbeater.cc:499] Master 127.24.149.126:40159 was elected leader, sending a full tablet report...
I20260812 06:16:46.285259 25772 raft_consensus.cc:697] T 4bae55ff194f4d83acdc68cae6fb694f P 6655e200ad2a4580a61edb24e18b8258 [term 1 LEADER]: Becoming Leader. State: Replica: 6655e200ad2a4580a61edb24e18b8258, State: Running, Role: LEADER
I20260812 06:16:46.285588 25772 consensus_queue.cc:237] T 4bae55ff194f4d83acdc68cae6fb694f P 6655e200ad2a4580a61edb24e18b8258 [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: "6655e200ad2a4580a61edb24e18b8258" member_type: VOTER last_known_addr { host: "127.24.149.65" port: 46621 } }
I20260812 06:16:46.287043 25531 catalog_manager.cc:5719] T 4bae55ff194f4d83acdc68cae6fb694f P 6655e200ad2a4580a61edb24e18b8258 reported cstate change: term changed from 0 to 1, leader changed from <none> to 6655e200ad2a4580a61edb24e18b8258 (127.24.149.65). New cstate: current_term: 1 leader_uuid: "6655e200ad2a4580a61edb24e18b8258" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "6655e200ad2a4580a61edb24e18b8258" member_type: VOTER last_known_addr { host: "127.24.149.65" port: 46621 } health_report { overall_health: HEALTHY } } }
I20260812 06:16:46.346302 25173 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.052s	user 0.018s	sys 0.004s
I20260812 06:16:46.501668 25751 maintenance_manager.cc:419] P 6655e200ad2a4580a61edb24e18b8258: Scheduling FlushMRSOp(4bae55ff194f4d83acdc68cae6fb694f): perf score=19.054940
I20260812 06:16:46.644276 25652 maintenance_manager.cc:643] P 6655e200ad2a4580a61edb24e18b8258: FlushMRSOp(4bae55ff194f4d83acdc68cae6fb694f) complete. Timing: real 0.142s	user 0.114s	sys 0.028s Metrics: {"bytes_written":12758756,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":63,"dirs.run_cpu_time_us":217,"dirs.run_wall_time_us":795,"drs_written":1,"lbm_read_time_us":85,"lbm_reads_lt_1ms":4,"lbm_write_time_us":37212,"lbm_writes_lt_1ms":768,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"update_count":1555}
I20260812 06:16:46.645155 25751 maintenance_manager.cc:419] P 6655e200ad2a4580a61edb24e18b8258: Scheduling LogGCOp(4bae55ff194f4d83acdc68cae6fb694f): free 20290830 bytes of WAL
I20260812 06:16:46.645407 25652 log_reader.cc:385] T 4bae55ff194f4d83acdc68cae6fb694f: removed 2 log segments from log reader
I20260812 06:16:46.645453 25652 log.cc:1079] T 4bae55ff194f4d83acdc68cae6fb694f P 6655e200ad2a4580a61edb24e18b8258: Deleting log segment in path: /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515400764805-25173-0/minicluster-data/ts-0-root/wals/4bae55ff194f4d83acdc68cae6fb694f/wal-000000001 (ops 1-6)
I20260812 06:16:46.645486 25652 log.cc:1079] T 4bae55ff194f4d83acdc68cae6fb694f P 6655e200ad2a4580a61edb24e18b8258: Deleting log segment in path: /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515400764805-25173-0/minicluster-data/ts-0-root/wals/4bae55ff194f4d83acdc68cae6fb694f/wal-000000002 (ops 7-10)
I20260812 06:16:46.650055 25652 maintenance_manager.cc:643] P 6655e200ad2a4580a61edb24e18b8258: LogGCOp(4bae55ff194f4d83acdc68cae6fb694f) complete. Timing: real 0.005s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:16:46.650429 25751 maintenance_manager.cc:419] P 6655e200ad2a4580a61edb24e18b8258: Scheduling FlushDeltaMemStoresOp(4bae55ff194f4d83acdc68cae6fb694f): perf score=2.188937
I20260812 06:16:46.666497 25652 maintenance_manager.cc:643] P 6655e200ad2a4580a61edb24e18b8258: FlushDeltaMemStoresOp(4bae55ff194f4d83acdc68cae6fb694f) complete. Timing: real 0.016s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4061633,"delete_count":0,"lbm_write_time_us":4032,"lbm_writes_lt_1ms":102,"reinsert_count":0,"update_count":495}
I20260812 06:16:46.666925 25751 maintenance_manager.cc:419] P 6655e200ad2a4580a61edb24e18b8258: Scheduling FlushDeltaMemStoresOp(4bae55ff194f4d83acdc68cae6fb694f): perf score=2.188937
I20260812 06:16:46.676385 25652 maintenance_manager.cc:643] P 6655e200ad2a4580a61edb24e18b8258: FlushDeltaMemStoresOp(4bae55ff194f4d83acdc68cae6fb694f) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3457,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:46.676805 25751 maintenance_manager.cc:419] P 6655e200ad2a4580a61edb24e18b8258: Scheduling MajorDeltaCompactionOp(4bae55ff194f4d83acdc68cae6fb694f): perf score=1.000000
I20260812 06:16:46.846199 25652 maintenance_manager.cc:643] P 6655e200ad2a4580a61edb24e18b8258: MajorDeltaCompactionOp(4bae55ff194f4d83acdc68cae6fb694f) complete. Timing: real 0.169s	user 0.108s	sys 0.059s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774794,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":309,"lbm_read_time_us":12294,"lbm_reads_lt_1ms":573,"lbm_write_time_us":32333,"lbm_writes_lt_1ms":543,"mutex_wait_us":46,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2560,"thread_start_us":376,"threads_started":5,"update_count":2500}
I20260812 06:16:46.846755 25751 maintenance_manager.cc:419] P 6655e200ad2a4580a61edb24e18b8258: Scheduling UndoDeltaBlockGCOp(4bae55ff194f4d83acdc68cae6fb694f): 16411405 bytes on disk
I20260812 06:16:46.847317 25652 maintenance_manager.cc:643] P 6655e200ad2a4580a61edb24e18b8258: UndoDeltaBlockGCOp(4bae55ff194f4d83acdc68cae6fb694f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":108,"lbm_reads_lt_1ms":4}
I20260812 06:16:46.847843 25751 maintenance_manager.cc:419] P 6655e200ad2a4580a61edb24e18b8258: Scheduling FlushDeltaMemStoresOp(4bae55ff194f4d83acdc68cae6fb694f): perf score=14.095187
I20260812 06:16:46.898590 25652 maintenance_manager.cc:643] P 6655e200ad2a4580a61edb24e18b8258: FlushDeltaMemStoresOp(4bae55ff194f4d83acdc68cae6fb694f) complete. Timing: real 0.051s	user 0.036s	sys 0.003s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19324,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:46.899027 25751 maintenance_manager.cc:419] P 6655e200ad2a4580a61edb24e18b8258: Scheduling FlushDeltaMemStoresOp(4bae55ff194f4d83acdc68cae6fb694f): perf score=2.188937
I20260812 06:16:46.909348 25652 maintenance_manager.cc:643] P 6655e200ad2a4580a61edb24e18b8258: FlushDeltaMemStoresOp(4bae55ff194f4d83acdc68cae6fb694f) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4018,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:46.909859 25751 maintenance_manager.cc:419] P 6655e200ad2a4580a61edb24e18b8258: Scheduling MajorDeltaCompactionOp(4bae55ff194f4d83acdc68cae6fb694f): perf score=1.000000
I20260812 06:16:47.069326 25652 maintenance_manager.cc:643] P 6655e200ad2a4580a61edb24e18b8258: MajorDeltaCompactionOp(4bae55ff194f4d83acdc68cae6fb694f) complete. Timing: real 0.159s	user 0.099s	sys 0.055s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1410,"lbm_read_time_us":9264,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31734,"lbm_writes_lt_1ms":543,"mutex_wait_us":351,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3072,"update_count":2500}
I20260812 06:16:47.070082 25751 maintenance_manager.cc:419] P 6655e200ad2a4580a61edb24e18b8258: Scheduling FlushDeltaMemStoresOp(4bae55ff194f4d83acdc68cae6fb694f): perf score=12.110812
I20260812 06:16:47.113379 25652 maintenance_manager.cc:643] P 6655e200ad2a4580a61edb24e18b8258: FlushDeltaMemStoresOp(4bae55ff194f4d83acdc68cae6fb694f) complete. Timing: real 0.043s	user 0.029s	sys 0.012s Metrics: {"bytes_written":13907424,"delete_count":0,"lbm_write_time_us":19209,"lbm_writes_lt_1ms":342,"reinsert_count":0,"update_count":1695}
I20260812 06:16:47.114007 25751 maintenance_manager.cc:419] P 6655e200ad2a4580a61edb24e18b8258: Scheduling FlushDeltaMemStoresOp(4bae55ff194f4d83acdc68cae6fb694f): perf score=1.196750
I20260812 06:16:47.126868 25652 maintenance_manager.cc:643] P 6655e200ad2a4580a61edb24e18b8258: FlushDeltaMemStoresOp(4bae55ff194f4d83acdc68cae6fb694f) complete. Timing: real 0.013s	user 0.008s	sys 0.000s Metrics: {"bytes_written":2502679,"delete_count":0,"lbm_write_time_us":3626,"lbm_writes_lt_1ms":64,"reinsert_count":0,"update_count":305}
I20260812 06:16:47.127436 25751 maintenance_manager.cc:419] P 6655e200ad2a4580a61edb24e18b8258: Scheduling MajorDeltaCompactionOp(4bae55ff194f4d83acdc68cae6fb694f): perf score=1.000000
I20260812 06:16:47.266840 25652 maintenance_manager.cc:643] P 6655e200ad2a4580a61edb24e18b8258: MajorDeltaCompactionOp(4bae55ff194f4d83acdc68cae6fb694f) complete. Timing: real 0.139s	user 0.091s	sys 0.047s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672231,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":170,"lbm_read_time_us":9156,"lbm_reads_lt_1ms":464,"lbm_write_time_us":22417,"lbm_writes_lt_1ms":443,"mutex_wait_us":3,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":13312,"update_count":2000}
I20260812 06:16:47.267474 25751 maintenance_manager.cc:419] P 6655e200ad2a4580a61edb24e18b8258: Scheduling FlushDeltaMemStoresOp(4bae55ff194f4d83acdc68cae6fb694f): perf score=14.095187
I20260812 06:16:47.322119 25652 maintenance_manager.cc:643] P 6655e200ad2a4580a61edb24e18b8258: FlushDeltaMemStoresOp(4bae55ff194f4d83acdc68cae6fb694f) complete. Timing: real 0.054s	user 0.027s	sys 0.021s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":22861,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:47.322620 25751 maintenance_manager.cc:419] P 6655e200ad2a4580a61edb24e18b8258: Scheduling FlushDeltaMemStoresOp(4bae55ff194f4d83acdc68cae6fb694f): perf score=2.188937
I20260812 06:16:47.343899 25652 maintenance_manager.cc:643] P 6655e200ad2a4580a61edb24e18b8258: FlushDeltaMemStoresOp(4bae55ff194f4d83acdc68cae6fb694f) complete. Timing: real 0.021s	user 0.006s	sys 0.015s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4053,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:47.344429 25751 maintenance_manager.cc:419] P 6655e200ad2a4580a61edb24e18b8258: Scheduling MajorDeltaCompactionOp(4bae55ff194f4d83acdc68cae6fb694f): perf score=1.000000
I20260812 06:16:47.543138 25652 maintenance_manager.cc:643] P 6655e200ad2a4580a61edb24e18b8258: MajorDeltaCompactionOp(4bae55ff194f4d83acdc68cae6fb694f) complete. Timing: real 0.199s	user 0.136s	sys 0.057s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":547,"lbm_read_time_us":13262,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32092,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10752,"update_count":2500}
I20260812 06:16:47.543836 25751 maintenance_manager.cc:419] P 6655e200ad2a4580a61edb24e18b8258: Scheduling FlushDeltaMemStoresOp(4bae55ff194f4d83acdc68cae6fb694f): perf score=14.095187
I20260812 06:16:47.594161 25652 maintenance_manager.cc:643] P 6655e200ad2a4580a61edb24e18b8258: FlushDeltaMemStoresOp(4bae55ff194f4d83acdc68cae6fb694f) complete. Timing: real 0.050s	user 0.014s	sys 0.033s Metrics: {"bytes_written":16409908,"delete_count":0,"lbm_write_time_us":22822,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:16:47.594602 25751 maintenance_manager.cc:419] P 6655e200ad2a4580a61edb24e18b8258: Scheduling FlushDeltaMemStoresOp(4bae55ff194f4d83acdc68cae6fb694f): perf score=2.188937
I20260812 06:16:47.606515 25652 maintenance_manager.cc:643] P 6655e200ad2a4580a61edb24e18b8258: FlushDeltaMemStoresOp(4bae55ff194f4d83acdc68cae6fb694f) complete. Timing: real 0.012s	user 0.003s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4734,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:47.607025 25751 maintenance_manager.cc:419] P 6655e200ad2a4580a61edb24e18b8258: Scheduling MajorDeltaCompactionOp(4bae55ff194f4d83acdc68cae6fb694f): perf score=1.000000
I20260812 06:16:47.793159 25652 maintenance_manager.cc:643] P 6655e200ad2a4580a61edb24e18b8258: MajorDeltaCompactionOp(4bae55ff194f4d83acdc68cae6fb694f) complete. Timing: real 0.186s	user 0.130s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774695,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":163,"lbm_read_time_us":12049,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29684,"lbm_writes_lt_1ms":543,"mutex_wait_us":37,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":15360,"update_count":2500}
I20260812 06:16:47.793898 25751 maintenance_manager.cc:419] P 6655e200ad2a4580a61edb24e18b8258: Scheduling FlushDeltaMemStoresOp(4bae55ff194f4d83acdc68cae6fb694f): perf score=14.095187
I20260812 06:16:47.921545 25652 maintenance_manager.cc:643] P 6655e200ad2a4580a61edb24e18b8258: FlushDeltaMemStoresOp(4bae55ff194f4d83acdc68cae6fb694f) complete. Timing: real 0.127s	user 0.024s	sys 0.031s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":25587,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:16:47.922220 25751 maintenance_manager.cc:419] P 6655e200ad2a4580a61edb24e18b8258: Scheduling FlushDeltaMemStoresOp(4bae55ff194f4d83acdc68cae6fb694f): perf score=10.126437
I20260812 06:16:48.028234 25652 maintenance_manager.cc:643] P 6655e200ad2a4580a61edb24e18b8258: FlushDeltaMemStoresOp(4bae55ff194f4d83acdc68cae6fb694f) complete. Timing: real 0.106s	user 0.018s	sys 0.015s Metrics: {"bytes_written":11856227,"delete_count":0,"lbm_write_time_us":14133,"lbm_writes_lt_1ms":292,"reinsert_count":0,"update_count":1445}
I20260812 06:16:48.029167 25751 maintenance_manager.cc:419] P 6655e200ad2a4580a61edb24e18b8258: Scheduling FlushDeltaMemStoresOp(4bae55ff194f4d83acdc68cae6fb694f): perf score=3.181125
I20260812 06:16:48.124127 25652 maintenance_manager.cc:643] P 6655e200ad2a4580a61edb24e18b8258: FlushDeltaMemStoresOp(4bae55ff194f4d83acdc68cae6fb694f) complete. Timing: real 0.095s	user 0.013s	sys 0.004s Metrics: {"bytes_written":4964174,"delete_count":0,"lbm_write_time_us":6709,"lbm_writes_lt_1ms":124,"reinsert_count":0,"update_count":605}
I20260812 06:16:48.124830 25751 maintenance_manager.cc:419] P 6655e200ad2a4580a61edb24e18b8258: Scheduling FlushDeltaMemStoresOp(4bae55ff194f4d83acdc68cae6fb694f): perf score=6.157687
I20260812 06:16:48.228274 25652 maintenance_manager.cc:643] P 6655e200ad2a4580a61edb24e18b8258: FlushDeltaMemStoresOp(4bae55ff194f4d83acdc68cae6fb694f) complete. Timing: real 0.103s	user 0.019s	sys 0.004s Metrics: {"bytes_written":8205079,"delete_count":0,"lbm_write_time_us":10815,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:16:48.228977 25751 maintenance_manager.cc:419] P 6655e200ad2a4580a61edb24e18b8258: Scheduling FlushDeltaMemStoresOp(4bae55ff194f4d83acdc68cae6fb694f): perf score=6.157687
I20260812 06:16:48.327992 25652 maintenance_manager.cc:643] P 6655e200ad2a4580a61edb24e18b8258: FlushDeltaMemStoresOp(4bae55ff194f4d83acdc68cae6fb694f) complete. Timing: real 0.099s	user 0.012s	sys 0.014s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":12154,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:16:48.328749 25751 maintenance_manager.cc:419] P 6655e200ad2a4580a61edb24e18b8258: Scheduling FlushDeltaMemStoresOp(4bae55ff194f4d83acdc68cae6fb694f): perf score=8.142062
I20260812 06:16:48.429790 25652 maintenance_manager.cc:643] P 6655e200ad2a4580a61edb24e18b8258: FlushDeltaMemStoresOp(4bae55ff194f4d83acdc68cae6fb694f) complete. Timing: real 0.101s	user 0.006s	sys 0.020s Metrics: {"bytes_written":10133211,"delete_count":0,"lbm_write_time_us":11976,"lbm_writes_lt_1ms":250,"reinsert_count":0,"update_count":1235}
I20260812 06:16:48.430418 25751 maintenance_manager.cc:419] P 6655e200ad2a4580a61edb24e18b8258: Scheduling FlushDeltaMemStoresOp(4bae55ff194f4d83acdc68cae6fb694f): perf score=8.142062
I20260812 06:16:48.534636 25652 maintenance_manager.cc:643] P 6655e200ad2a4580a61edb24e18b8258: FlushDeltaMemStoresOp(4bae55ff194f4d83acdc68cae6fb694f) complete. Timing: real 0.104s	user 0.016s	sys 0.012s Metrics: {"bytes_written":9969124,"delete_count":0,"lbm_write_time_us":12403,"lbm_writes_lt_1ms":246,"reinsert_count":0,"update_count":1215}
I20260812 06:16:48.535620 25751 maintenance_manager.cc:419] P 6655e200ad2a4580a61edb24e18b8258: Scheduling FlushDeltaMemStoresOp(4bae55ff194f4d83acdc68cae6fb694f): perf score=6.157687
I20260812 06:16:48.633863 25652 maintenance_manager.cc:643] P 6655e200ad2a4580a61edb24e18b8258: FlushDeltaMemStoresOp(4bae55ff194f4d83acdc68cae6fb694f) complete. Timing: real 0.098s	user 0.013s	sys 0.014s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":12181,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:16:48.634665 25751 maintenance_manager.cc:419] P 6655e200ad2a4580a61edb24e18b8258: Scheduling FlushDeltaMemStoresOp(4bae55ff194f4d83acdc68cae6fb694f): perf score=6.157687
I20260812 06:16:48.739050 25652 maintenance_manager.cc:643] P 6655e200ad2a4580a61edb24e18b8258: FlushDeltaMemStoresOp(4bae55ff194f4d83acdc68cae6fb694f) complete. Timing: real 0.104s	user 0.012s	sys 0.007s Metrics: {"bytes_written":8205079,"delete_count":0,"lbm_write_time_us":9030,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:16:48.739681 25751 maintenance_manager.cc:419] P 6655e200ad2a4580a61edb24e18b8258: Scheduling FlushDeltaMemStoresOp(4bae55ff194f4d83acdc68cae6fb694f): perf score=10.126437
I20260812 06:16:48.844055 25652 maintenance_manager.cc:643] P 6655e200ad2a4580a61edb24e18b8258: FlushDeltaMemStoresOp(4bae55ff194f4d83acdc68cae6fb694f) complete. Timing: real 0.104s	user 0.023s	sys 0.015s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":16324,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:48.844588 25751 maintenance_manager.cc:419] P 6655e200ad2a4580a61edb24e18b8258: Scheduling FlushDeltaMemStoresOp(4bae55ff194f4d83acdc68cae6fb694f): perf score=6.157687
I20260812 06:16:48.945741 25652 maintenance_manager.cc:643] P 6655e200ad2a4580a61edb24e18b8258: FlushDeltaMemStoresOp(4bae55ff194f4d83acdc68cae6fb694f) complete. Timing: real 0.101s	user 0.012s	sys 0.008s Metrics: {"bytes_written":8205077,"delete_count":0,"lbm_write_time_us":8867,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:16:48.946487 25751 maintenance_manager.cc:419] P 6655e200ad2a4580a61edb24e18b8258: Scheduling FlushDeltaMemStoresOp(4bae55ff194f4d83acdc68cae6fb694f): perf score=7.149875
I20260812 06:16:49.044335 25652 maintenance_manager.cc:643] P 6655e200ad2a4580a61edb24e18b8258: FlushDeltaMemStoresOp(4bae55ff194f4d83acdc68cae6fb694f) complete. Timing: real 0.098s	user 0.016s	sys 0.011s Metrics: {"bytes_written":9312730,"delete_count":0,"lbm_write_time_us":11782,"lbm_writes_lt_1ms":230,"reinsert_count":0,"update_count":1135}
I20260812 06:16:49.044953 25751 maintenance_manager.cc:419] P 6655e200ad2a4580a61edb24e18b8258: Scheduling FlushDeltaMemStoresOp(4bae55ff194f4d83acdc68cae6fb694f): perf score=6.157687
I20260812 06:16:49.142205 25652 maintenance_manager.cc:643] P 6655e200ad2a4580a61edb24e18b8258: FlushDeltaMemStoresOp(4bae55ff194f4d83acdc68cae6fb694f) complete. Timing: real 0.097s	user 0.017s	sys 0.005s Metrics: {"bytes_written":7548700,"delete_count":0,"lbm_write_time_us":10043,"lbm_writes_lt_1ms":187,"reinsert_count":0,"update_count":920}
I20260812 06:16:49.142879 25751 maintenance_manager.cc:419] P 6655e200ad2a4580a61edb24e18b8258: Scheduling FlushDeltaMemStoresOp(4bae55ff194f4d83acdc68cae6fb694f): perf score=9.134250
I20260812 06:16:49.243934 25652 maintenance_manager.cc:643] P 6655e200ad2a4580a61edb24e18b8258: FlushDeltaMemStoresOp(4bae55ff194f4d83acdc68cae6fb694f) complete. Timing: real 0.101s	user 0.017s	sys 0.012s Metrics: {"bytes_written":10502427,"delete_count":0,"lbm_write_time_us":12021,"lbm_writes_lt_1ms":259,"reinsert_count":0,"update_count":1280}
I20260812 06:16:49.245076 25751 maintenance_manager.cc:419] P 6655e200ad2a4580a61edb24e18b8258: Scheduling FlushDeltaMemStoresOp(4bae55ff194f4d83acdc68cae6fb694f): perf score=8.142062
I20260812 06:16:49.349858 25652 maintenance_manager.cc:643] P 6655e200ad2a4580a61edb24e18b8258: FlushDeltaMemStoresOp(4bae55ff194f4d83acdc68cae6fb694f) complete. Timing: real 0.105s	user 0.018s	sys 0.009s Metrics: {"bytes_written":9558878,"delete_count":0,"lbm_write_time_us":12074,"lbm_writes_lt_1ms":236,"reinsert_count":0,"update_count":1165}
I20260812 06:16:49.350550 25751 maintenance_manager.cc:419] P 6655e200ad2a4580a61edb24e18b8258: Scheduling FlushDeltaMemStoresOp(4bae55ff194f4d83acdc68cae6fb694f): perf score=7.149875
I20260812 06:16:49.456591 25652 maintenance_manager.cc:643] P 6655e200ad2a4580a61edb24e18b8258: FlushDeltaMemStoresOp(4bae55ff194f4d83acdc68cae6fb694f) complete. Timing: real 0.106s	user 0.016s	sys 0.012s Metrics: {"bytes_written":8615323,"delete_count":0,"lbm_write_time_us":11341,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:16:49.457186 25751 maintenance_manager.cc:419] P 6655e200ad2a4580a61edb24e18b8258: Scheduling FlushDeltaMemStoresOp(4bae55ff194f4d83acdc68cae6fb694f): perf score=9.134250
I20260812 06:16:49.555881 25652 maintenance_manager.cc:643] P 6655e200ad2a4580a61edb24e18b8258: FlushDeltaMemStoresOp(4bae55ff194f4d83acdc68cae6fb694f) complete. Timing: real 0.098s	user 0.011s	sys 0.014s Metrics: {"bytes_written":10871650,"delete_count":0,"lbm_write_time_us":10494,"lbm_writes_lt_1ms":268,"reinsert_count":0,"update_count":1325}
I20260812 06:16:49.557041 25751 maintenance_manager.cc:419] P 6655e200ad2a4580a61edb24e18b8258: Scheduling FlushDeltaMemStoresOp(4bae55ff194f4d83acdc68cae6fb694f): perf score=7.149875
I20260812 06:16:49.656137 25652 maintenance_manager.cc:643] P 6655e200ad2a4580a61edb24e18b8258: FlushDeltaMemStoresOp(4bae55ff194f4d83acdc68cae6fb694f) complete. Timing: real 0.099s	user 0.028s	sys 0.000s Metrics: {"bytes_written":8574302,"delete_count":0,"lbm_write_time_us":11776,"lbm_writes_lt_1ms":212,"reinsert_count":0,"update_count":1045}
I20260812 06:16:49.656993 25751 maintenance_manager.cc:419] P 6655e200ad2a4580a61edb24e18b8258: Scheduling FlushDeltaMemStoresOp(4bae55ff194f4d83acdc68cae6fb694f): perf score=7.149875
I20260812 06:16:49.754901 25652 maintenance_manager.cc:643] P 6655e200ad2a4580a61edb24e18b8258: FlushDeltaMemStoresOp(4bae55ff194f4d83acdc68cae6fb694f) complete. Timing: real 0.098s	user 0.018s	sys 0.010s Metrics: {"bytes_written":8861469,"delete_count":0,"lbm_write_time_us":11990,"lbm_writes_lt_1ms":219,"reinsert_count":0,"update_count":1080}
I20260812 06:16:49.755894 25751 maintenance_manager.cc:419] P 6655e200ad2a4580a61edb24e18b8258: Scheduling FlushDeltaMemStoresOp(4bae55ff194f4d83acdc68cae6fb694f): perf score=6.157687
I20260812 06:16:49.856323 25652 maintenance_manager.cc:643] P 6655e200ad2a4580a61edb24e18b8258: FlushDeltaMemStoresOp(4bae55ff194f4d83acdc68cae6fb694f) complete. Timing: real 0.100s	user 0.016s	sys 0.005s Metrics: {"bytes_written":8205079,"delete_count":0,"lbm_write_time_us":8919,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:16:49.856990 25751 maintenance_manager.cc:419] P 6655e200ad2a4580a61edb24e18b8258: Scheduling FlushDeltaMemStoresOp(4bae55ff194f4d83acdc68cae6fb694f): perf score=8.142062
I20260812 06:16:49.963717 25652 maintenance_manager.cc:643] P 6655e200ad2a4580a61edb24e18b8258: FlushDeltaMemStoresOp(4bae55ff194f4d83acdc68cae6fb694f) complete. Timing: real 0.107s	user 0.017s	sys 0.014s Metrics: {"bytes_written":9887067,"delete_count":0,"lbm_write_time_us":12420,"lbm_writes_lt_1ms":244,"reinsert_count":0,"update_count":1205}
I20260812 06:16:49.964617 25751 maintenance_manager.cc:419] P 6655e200ad2a4580a61edb24e18b8258: Scheduling FlushDeltaMemStoresOp(4bae55ff194f4d83acdc68cae6fb694f): perf score=6.157687
I20260812 06:16:50.058768 25652 maintenance_manager.cc:643] P 6655e200ad2a4580a61edb24e18b8258: FlushDeltaMemStoresOp(4bae55ff194f4d83acdc68cae6fb694f) complete. Timing: real 0.094s	user 0.010s	sys 0.016s Metrics: {"bytes_written":8123034,"delete_count":0,"lbm_write_time_us":15624,"lbm_writes_lt_1ms":201,"reinsert_count":0,"update_count":990}
I20260812 06:16:50.059762 25751 maintenance_manager.cc:419] P 6655e200ad2a4580a61edb24e18b8258: Scheduling FlushDeltaMemStoresOp(4bae55ff194f4d83acdc68cae6fb694f): perf score=3.181125
I20260812 06:16:50.160822 25652 maintenance_manager.cc:643] P 6655e200ad2a4580a61edb24e18b8258: FlushDeltaMemStoresOp(4bae55ff194f4d83acdc68cae6fb694f) complete. Timing: real 0.101s	user 0.023s	sys 0.009s Metrics: {"bytes_written":5087242,"delete_count":0,"lbm_write_time_us":21319,"lbm_writes_lt_1ms":127,"reinsert_count":0,"update_count":620}
I20260812 06:16:50.161857 25751 maintenance_manager.cc:419] P 6655e200ad2a4580a61edb24e18b8258: Scheduling FlushDeltaMemStoresOp(4bae55ff194f4d83acdc68cae6fb694f): perf score=8.142062
I20260812 06:16:50.262779 25652 maintenance_manager.cc:643] P 6655e200ad2a4580a61edb24e18b8258: FlushDeltaMemStoresOp(4bae55ff194f4d83acdc68cae6fb694f) complete. Timing: real 0.101s	user 0.024s	sys 0.012s Metrics: {"bytes_written":9722974,"delete_count":0,"lbm_write_time_us":19279,"lbm_writes_lt_1ms":240,"reinsert_count":0,"update_count":1185}
I20260812 06:16:50.263953 25751 maintenance_manager.cc:419] P 6655e200ad2a4580a61edb24e18b8258: Scheduling FlushDeltaMemStoresOp(4bae55ff194f4d83acdc68cae6fb694f): perf score=3.181125
I20260812 06:16:50.362958 25652 maintenance_manager.cc:643] P 6655e200ad2a4580a61edb24e18b8258: FlushDeltaMemStoresOp(4bae55ff194f4d83acdc68cae6fb694f) complete. Timing: real 0.099s	user 0.002s	sys 0.033s Metrics: {"bytes_written":5210310,"delete_count":0,"lbm_write_time_us":23508,"lbm_writes_lt_1ms":130,"reinsert_count":0,"update_count":635}
I20260812 06:16:50.363622 25751 maintenance_manager.cc:419] P 6655e200ad2a4580a61edb24e18b8258: Scheduling FlushDeltaMemStoresOp(4bae55ff194f4d83acdc68cae6fb694f): perf score=5.165500
I20260812 06:16:50.465027 25652 maintenance_manager.cc:643] P 6655e200ad2a4580a61edb24e18b8258: FlushDeltaMemStoresOp(4bae55ff194f4d83acdc68cae6fb694f) complete. Timing: real 0.101s	user 0.020s	sys 0.032s Metrics: {"bytes_written":7097432,"delete_count":0,"lbm_write_time_us":35428,"lbm_writes_lt_1ms":176,"reinsert_count":0,"update_count":865}
I20260812 06:16:50.466061 25751 maintenance_manager.cc:419] P 6655e200ad2a4580a61edb24e18b8258: Scheduling FlushDeltaMemStoresOp(4bae55ff194f4d83acdc68cae6fb694f): perf score=6.157687
I20260812 06:16:50.566665 25652 maintenance_manager.cc:643] P 6655e200ad2a4580a61edb24e18b8258: FlushDeltaMemStoresOp(4bae55ff194f4d83acdc68cae6fb694f) complete. Timing: real 0.100s	user 0.029s	sys 0.031s Metrics: {"bytes_written":8205077,"delete_count":0,"lbm_write_time_us":40966,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:16:50.568054 25751 maintenance_manager.cc:419] P 6655e200ad2a4580a61edb24e18b8258: Scheduling FlushDeltaMemStoresOp(4bae55ff194f4d83acdc68cae6fb694f): perf score=3.181125
I20260812 06:16:50.590569 25652 maintenance_manager.cc:643] P 6655e200ad2a4580a61edb24e18b8258: FlushDeltaMemStoresOp(4bae55ff194f4d83acdc68cae6fb694f) complete. Timing: real 0.022s	user 0.013s	sys 0.005s Metrics: {"bytes_written":4512902,"delete_count":0,"lbm_write_time_us":8203,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:16:50.591194 25751 maintenance_manager.cc:419] P 6655e200ad2a4580a61edb24e18b8258: Scheduling FlushDeltaMemStoresOp(4bae55ff194f4d83acdc68cae6fb694f): perf score=2.188937
I20260812 06:16:50.601503 25652 maintenance_manager.cc:643] P 6655e200ad2a4580a61edb24e18b8258: FlushDeltaMemStoresOp(4bae55ff194f4d83acdc68cae6fb694f) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3966,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:50.602046 25751 maintenance_manager.cc:419] P 6655e200ad2a4580a61edb24e18b8258: Scheduling FlushMRSOp(4bae55ff194f4d83acdc68cae6fb694f): perf score=2.187753
I20260812 06:16:50.681427 25652 maintenance_manager.cc:643] P 6655e200ad2a4580a61edb24e18b8258: FlushMRSOp(4bae55ff194f4d83acdc68cae6fb694f) complete. Timing: real 0.079s	user 0.032s	sys 0.028s Metrics: {"bytes_written":3488466,"cfile_init":1,"dirs.queue_time_us":297,"dirs.run_cpu_time_us":270,"dirs.run_wall_time_us":1626,"drs_written":1,"lbm_read_time_us":60,"lbm_reads_lt_1ms":4,"lbm_write_time_us":17626,"lbm_writes_1-10_ms":8,"lbm_writes_lt_1ms":41,"peak_mem_usage":0,"rows_written":85,"thread_start_us":108,"threads_started":1}
I20260812 06:16:50.682215 25751 maintenance_manager.cc:419] P 6655e200ad2a4580a61edb24e18b8258: Scheduling LogGCOp(4bae55ff194f4d83acdc68cae6fb694f): free 349189241 bytes of WAL
I20260812 06:16:50.682513 25652 log_reader.cc:385] T 4bae55ff194f4d83acdc68cae6fb694f: removed 34 log segments from log reader
I20260812 06:16:50.682579 25652 log.cc:1079] T 4bae55ff194f4d83acdc68cae6fb694f P 6655e200ad2a4580a61edb24e18b8258: Deleting log segment in path: /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515400764805-25173-0/minicluster-data/ts-0-root/wals/4bae55ff194f4d83acdc68cae6fb694f/wal-000000003 (ops 11-15)
I20260812 06:16:50.682631 25652 log.cc:1079] T 4bae55ff194f4d83acdc68cae6fb694f P 6655e200ad2a4580a61edb24e18b8258: Deleting log segment in path: /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515400764805-25173-0/minicluster-data/ts-0-root/wals/4bae55ff194f4d83acdc68cae6fb694f/wal-000000004 (ops 16-20)
I20260812 06:16:50.682688 25652 log.cc:1079] T 4bae55ff194f4d83acdc68cae6fb694f P 6655e200ad2a4580a61edb24e18b8258: Deleting log segment in path: /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515400764805-25173-0/minicluster-data/ts-0-root/wals/4bae55ff194f4d83acdc68cae6fb694f/wal-000000005 (ops 21-25)
I20260812 06:16:50.682734 25652 log.cc:1079] T 4bae55ff194f4d83acdc68cae6fb694f P 6655e200ad2a4580a61edb24e18b8258: Deleting log segment in path: /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515400764805-25173-0/minicluster-data/ts-0-root/wals/4bae55ff194f4d83acdc68cae6fb694f/wal-000000006 (ops 26-30)
I20260812 06:16:50.682775 25652 log.cc:1079] T 4bae55ff194f4d83acdc68cae6fb694f P 6655e200ad2a4580a61edb24e18b8258: Deleting log segment in path: /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515400764805-25173-0/minicluster-data/ts-0-root/wals/4bae55ff194f4d83acdc68cae6fb694f/wal-000000007 (ops 31-35)
I20260812 06:16:50.682814 25652 log.cc:1079] T 4bae55ff194f4d83acdc68cae6fb694f P 6655e200ad2a4580a61edb24e18b8258: Deleting log segment in path: /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515400764805-25173-0/minicluster-data/ts-0-root/wals/4bae55ff194f4d83acdc68cae6fb694f/wal-000000008 (ops 36-40)
I20260812 06:16:50.682852 25652 log.cc:1079] T 4bae55ff194f4d83acdc68cae6fb694f P 6655e200ad2a4580a61edb24e18b8258: Deleting log segment in path: /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515400764805-25173-0/minicluster-data/ts-0-root/wals/4bae55ff194f4d83acdc68cae6fb694f/wal-000000009 (ops 41-45)
I20260812 06:16:50.682897 25652 log.cc:1079] T 4bae55ff194f4d83acdc68cae6fb694f P 6655e200ad2a4580a61edb24e18b8258: Deleting log segment in path: /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515400764805-25173-0/minicluster-data/ts-0-root/wals/4bae55ff194f4d83acdc68cae6fb694f/wal-000000010 (ops 46-50)
I20260812 06:16:50.682936 25652 log.cc:1079] T 4bae55ff194f4d83acdc68cae6fb694f P 6655e200ad2a4580a61edb24e18b8258: Deleting log segment in path: /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515400764805-25173-0/minicluster-data/ts-0-root/wals/4bae55ff194f4d83acdc68cae6fb694f/wal-000000011 (ops 51-55)
I20260812 06:16:50.682974 25652 log.cc:1079] T 4bae55ff194f4d83acdc68cae6fb694f P 6655e200ad2a4580a61edb24e18b8258: Deleting log segment in path: /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515400764805-25173-0/minicluster-data/ts-0-root/wals/4bae55ff194f4d83acdc68cae6fb694f/wal-000000012 (ops 56-60)
I20260812 06:16:50.683012 25652 log.cc:1079] T 4bae55ff194f4d83acdc68cae6fb694f P 6655e200ad2a4580a61edb24e18b8258: Deleting log segment in path: /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515400764805-25173-0/minicluster-data/ts-0-root/wals/4bae55ff194f4d83acdc68cae6fb694f/wal-000000013 (ops 61-65)
I20260812 06:16:50.683050 25652 log.cc:1079] T 4bae55ff194f4d83acdc68cae6fb694f P 6655e200ad2a4580a61edb24e18b8258: Deleting log segment in path: /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515400764805-25173-0/minicluster-data/ts-0-root/wals/4bae55ff194f4d83acdc68cae6fb694f/wal-000000014 (ops 66-70)
I20260812 06:16:50.683117 25652 log.cc:1079] T 4bae55ff194f4d83acdc68cae6fb694f P 6655e200ad2a4580a61edb24e18b8258: Deleting log segment in path: /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515400764805-25173-0/minicluster-data/ts-0-root/wals/4bae55ff194f4d83acdc68cae6fb694f/wal-000000015 (ops 71-75)
I20260812 06:16:50.683157 25652 log.cc:1079] T 4bae55ff194f4d83acdc68cae6fb694f P 6655e200ad2a4580a61edb24e18b8258: Deleting log segment in path: /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515400764805-25173-0/minicluster-data/ts-0-root/wals/4bae55ff194f4d83acdc68cae6fb694f/wal-000000016 (ops 76-80)
I20260812 06:16:50.683197 25652 log.cc:1079] T 4bae55ff194f4d83acdc68cae6fb694f P 6655e200ad2a4580a61edb24e18b8258: Deleting log segment in path: /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515400764805-25173-0/minicluster-data/ts-0-root/wals/4bae55ff194f4d83acdc68cae6fb694f/wal-000000017 (ops 81-85)
I20260812 06:16:50.683234 25652 log.cc:1079] T 4bae55ff194f4d83acdc68cae6fb694f P 6655e200ad2a4580a61edb24e18b8258: Deleting log segment in path: /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515400764805-25173-0/minicluster-data/ts-0-root/wals/4bae55ff194f4d83acdc68cae6fb694f/wal-000000018 (ops 86-90)
I20260812 06:16:50.683274 25652 log.cc:1079] T 4bae55ff194f4d83acdc68cae6fb694f P 6655e200ad2a4580a61edb24e18b8258: Deleting log segment in path: /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515400764805-25173-0/minicluster-data/ts-0-root/wals/4bae55ff194f4d83acdc68cae6fb694f/wal-000000019 (ops 91-95)
I20260812 06:16:50.683312 25652 log.cc:1079] T 4bae55ff194f4d83acdc68cae6fb694f P 6655e200ad2a4580a61edb24e18b8258: Deleting log segment in path: /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515400764805-25173-0/minicluster-data/ts-0-root/wals/4bae55ff194f4d83acdc68cae6fb694f/wal-000000020 (ops 96-100)
I20260812 06:16:50.683349 25652 log.cc:1079] T 4bae55ff194f4d83acdc68cae6fb694f P 6655e200ad2a4580a61edb24e18b8258: Deleting log segment in path: /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515400764805-25173-0/minicluster-data/ts-0-root/wals/4bae55ff194f4d83acdc68cae6fb694f/wal-000000021 (ops 101-105)
I20260812 06:16:50.683384 25652 log.cc:1079] T 4bae55ff194f4d83acdc68cae6fb694f P 6655e200ad2a4580a61edb24e18b8258: Deleting log segment in path: /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515400764805-25173-0/minicluster-data/ts-0-root/wals/4bae55ff194f4d83acdc68cae6fb694f/wal-000000022 (ops 106-110)
I20260812 06:16:50.683425 25652 log.cc:1079] T 4bae55ff194f4d83acdc68cae6fb694f P 6655e200ad2a4580a61edb24e18b8258: Deleting log segment in path: /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515400764805-25173-0/minicluster-data/ts-0-root/wals/4bae55ff194f4d83acdc68cae6fb694f/wal-000000023 (ops 111-115)
I20260812 06:16:50.683463 25652 log.cc:1079] T 4bae55ff194f4d83acdc68cae6fb694f P 6655e200ad2a4580a61edb24e18b8258: Deleting log segment in path: /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515400764805-25173-0/minicluster-data/ts-0-root/wals/4bae55ff194f4d83acdc68cae6fb694f/wal-000000024 (ops 116-120)
I20260812 06:16:50.683502 25652 log.cc:1079] T 4bae55ff194f4d83acdc68cae6fb694f P 6655e200ad2a4580a61edb24e18b8258: Deleting log segment in path: /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515400764805-25173-0/minicluster-data/ts-0-root/wals/4bae55ff194f4d83acdc68cae6fb694f/wal-000000025 (ops 121-125)
I20260812 06:16:50.683542 25652 log.cc:1079] T 4bae55ff194f4d83acdc68cae6fb694f P 6655e200ad2a4580a61edb24e18b8258: Deleting log segment in path: /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515400764805-25173-0/minicluster-data/ts-0-root/wals/4bae55ff194f4d83acdc68cae6fb694f/wal-000000026 (ops 126-130)
I20260812 06:16:50.683581 25652 log.cc:1079] T 4bae55ff194f4d83acdc68cae6fb694f P 6655e200ad2a4580a61edb24e18b8258: Deleting log segment in path: /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515400764805-25173-0/minicluster-data/ts-0-root/wals/4bae55ff194f4d83acdc68cae6fb694f/wal-000000027 (ops 131-134)
I20260812 06:16:50.683624 25652 log.cc:1079] T 4bae55ff194f4d83acdc68cae6fb694f P 6655e200ad2a4580a61edb24e18b8258: Deleting log segment in path: /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515400764805-25173-0/minicluster-data/ts-0-root/wals/4bae55ff194f4d83acdc68cae6fb694f/wal-000000028 (ops 135-139)
I20260812 06:16:50.683662 25652 log.cc:1079] T 4bae55ff194f4d83acdc68cae6fb694f P 6655e200ad2a4580a61edb24e18b8258: Deleting log segment in path: /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515400764805-25173-0/minicluster-data/ts-0-root/wals/4bae55ff194f4d83acdc68cae6fb694f/wal-000000029 (ops 140-144)
I20260812 06:16:50.683701 25652 log.cc:1079] T 4bae55ff194f4d83acdc68cae6fb694f P 6655e200ad2a4580a61edb24e18b8258: Deleting log segment in path: /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515400764805-25173-0/minicluster-data/ts-0-root/wals/4bae55ff194f4d83acdc68cae6fb694f/wal-000000030 (ops 145-148)
I20260812 06:16:50.683738 25652 log.cc:1079] T 4bae55ff194f4d83acdc68cae6fb694f P 6655e200ad2a4580a61edb24e18b8258: Deleting log segment in path: /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515400764805-25173-0/minicluster-data/ts-0-root/wals/4bae55ff194f4d83acdc68cae6fb694f/wal-000000031 (ops 149-153)
I20260812 06:16:50.683775 25652 log.cc:1079] T 4bae55ff194f4d83acdc68cae6fb694f P 6655e200ad2a4580a61edb24e18b8258: Deleting log segment in path: /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515400764805-25173-0/minicluster-data/ts-0-root/wals/4bae55ff194f4d83acdc68cae6fb694f/wal-000000032 (ops 154-158)
I20260812 06:16:50.683813 25652 log.cc:1079] T 4bae55ff194f4d83acdc68cae6fb694f P 6655e200ad2a4580a61edb24e18b8258: Deleting log segment in path: /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515400764805-25173-0/minicluster-data/ts-0-root/wals/4bae55ff194f4d83acdc68cae6fb694f/wal-000000033 (ops 159-163)
I20260812 06:16:50.683851 25652 log.cc:1079] T 4bae55ff194f4d83acdc68cae6fb694f P 6655e200ad2a4580a61edb24e18b8258: Deleting log segment in path: /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515400764805-25173-0/minicluster-data/ts-0-root/wals/4bae55ff194f4d83acdc68cae6fb694f/wal-000000034 (ops 164-168)
I20260812 06:16:50.683898 25652 log.cc:1079] T 4bae55ff194f4d83acdc68cae6fb694f P 6655e200ad2a4580a61edb24e18b8258: Deleting log segment in path: /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515400764805-25173-0/minicluster-data/ts-0-root/wals/4bae55ff194f4d83acdc68cae6fb694f/wal-000000035 (ops 169-173)
I20260812 06:16:50.683936 25652 log.cc:1079] T 4bae55ff194f4d83acdc68cae6fb694f P 6655e200ad2a4580a61edb24e18b8258: Deleting log segment in path: /tmp/dist-test-taskSaVT7b/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515400764805-25173-0/minicluster-data/ts-0-root/wals/4bae55ff194f4d83acdc68cae6fb694f/wal-000000036 (ops 174-178)
I20260812 06:16:50.764045 25652 maintenance_manager.cc:643] P 6655e200ad2a4580a61edb24e18b8258: LogGCOp(4bae55ff194f4d83acdc68cae6fb694f) complete. Timing: real 0.082s	user 0.000s	sys 0.081s Metrics: {}
I20260812 06:16:50.764488 25751 maintenance_manager.cc:419] P 6655e200ad2a4580a61edb24e18b8258: Scheduling FlushDeltaMemStoresOp(4bae55ff194f4d83acdc68cae6fb694f): perf score=6.157687
I20260812 06:16:50.795447 25652 maintenance_manager.cc:643] P 6655e200ad2a4580a61edb24e18b8258: FlushDeltaMemStoresOp(4bae55ff194f4d83acdc68cae6fb694f) complete. Timing: real 0.031s	user 0.008s	sys 0.020s Metrics: {"bytes_written":8205080,"delete_count":0,"lbm_write_time_us":13422,"lbm_writes_lt_1ms":203,"mutex_wait_us":48,"reinsert_count":0,"update_count":1000}
I20260812 06:16:50.795903 25751 maintenance_manager.cc:419] P 6655e200ad2a4580a61edb24e18b8258: Scheduling FlushDeltaMemStoresOp(4bae55ff194f4d83acdc68cae6fb694f): perf score=2.188937
I20260812 06:16:50.811600 25652 maintenance_manager.cc:643] P 6655e200ad2a4580a61edb24e18b8258: FlushDeltaMemStoresOp(4bae55ff194f4d83acdc68cae6fb694f) complete. Timing: real 0.015s	user 0.003s	sys 0.012s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5838,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:50.812273 25751 maintenance_manager.cc:419] P 6655e200ad2a4580a61edb24e18b8258: Scheduling UndoDeltaBlockGCOp(4bae55ff194f4d83acdc68cae6fb694f): 1093 bytes on disk
I20260812 06:16:50.812844 25652 maintenance_manager.cc:643] P 6655e200ad2a4580a61edb24e18b8258: UndoDeltaBlockGCOp(4bae55ff194f4d83acdc68cae6fb694f) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":74,"lbm_reads_lt_1ms":4}
I20260812 06:16:50.813444 25751 maintenance_manager.cc:419] P 6655e200ad2a4580a61edb24e18b8258: Scheduling MajorDeltaCompactionOp(4bae55ff194f4d83acdc68cae6fb694f): perf score=1.000000
I20260812 06:16:51.418413 25173 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.072s	user 1.743s	sys 0.158s
I20260812 06:16:53.582031 25671 rpcz_store.cc:275] Call kudu.tserver.TabletServerService.Scan from 127.0.0.1:50664 (request call id 202) took 2161 ms. Trace:
I20260812 06:16:53.582206 25671 rpcz_store.cc:276] 0812 06:16:51.420500 (+     0us) service_pool.cc:167] Inserting onto call queue
0812 06:16:51.420614 (+   114us) service_pool.cc:224] Handling call
0812 06:16:51.420831 (+   217us) tablet_service.cc:2890] Created scanner da8d73b84aaf454ea205b05fef276a6c for tablet 4bae55ff194f4d83acdc68cae6fb694f, query id is 498e8bef323844158e3313b1a146ee3b
0812 06:16:51.421169 (+   338us) tablet_service.cc:3030] Creating iterator
0812 06:16:51.421196 (+    27us) tablet_service.cc:3408] Waiting safe time to advance
0812 06:16:51.421203 (+     7us) tablet_service.cc:3415] Waiting for operations to commit
0812 06:16:51.421220 (+    17us) tablet_service.cc:3431] All operations in snapshot committed. Waited for 17 microseconds
0812 06:16:51.421269 (+    49us) tablet_service.cc:3055] Iterator created
0812 06:16:53.505461 (+2084192us) tablet_service.cc:3077] Iterator init: OK
0812 06:16:53.505519 (+    58us) tablet_service.cc:3120] has_more: true
0812 06:16:53.505586 (+    67us) tablet_service.cc:3137] Continuing scan request
0812 06:16:53.505662 (+    76us) tablet_service.cc:3201] Found scanner da8d73b84aaf454ea205b05fef276a6c for tablet 4bae55ff194f4d83acdc68cae6fb694f, query id is 498e8bef323844158e3313b1a146ee3b
0812 06:16:53.582011 (+ 76349us) inbound_call.cc:177] Queueing success response
Metrics: {"cfile_cache_hit":34,"cfile_cache_hit_bytes":87929,"cfile_cache_miss":6431,"cfile_cache_miss_bytes":266732813,"cfile_init":5,"delta_iterators_relevant":36,"lbm_read_time_us":166730,"lbm_reads_1-10_ms":5,"lbm_reads_lt_1ms":6446,"rowset_iterators":2,"scanner_bytes_read":2950785}
W20260812 06:16:53.590235 25173 scanner-internal.cc:458] Time spent opening tablet: real 2.171s	user 0.001s	sys 0.000s
I20260812 06:16:53.594726 25173 heavy-update-compaction-itest.cc:265] Time spent scanning: real 2.176s	user 0.002s	sys 0.000s
I20260812 06:16:53.595368 25173 tablet_server.cc:179] TabletServer@127.24.149.65:0 shutting down...
I20260812 06:16:54.115628 25652 maintenance_manager.cc:643] P 6655e200ad2a4580a61edb24e18b8258: MajorDeltaCompactionOp(4bae55ff194f4d83acdc68cae6fb694f) complete. Timing: real 3.302s	user 1.102s	sys 2.195s Metrics: {"cfile_cache_miss":6461,"cfile_cache_miss_bytes":266820531,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":31,"delta_iterators_relevant":31,"dirs.queue_time_us":1618,"lbm_read_time_us":111364,"lbm_reads_lt_1ms":6497,"lbm_write_time_us":736699,"lbm_writes_lt_1ms":6448,"peak_mem_usage":796283648,"reinsert_count":0,"spinlock_wait_cycles":14592,"thread_start_us":639,"threads_started":8,"update_count":32000,"wal-append.queue_time_us":258}
I20260812 06:16:54.116394 25173 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:16:54.116747 25173 tablet_replica.cc:333] T 4bae55ff194f4d83acdc68cae6fb694f P 6655e200ad2a4580a61edb24e18b8258: stopping tablet replica
I20260812 06:16:54.116955 25173 raft_consensus.cc:2243] T 4bae55ff194f4d83acdc68cae6fb694f P 6655e200ad2a4580a61edb24e18b8258 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:54.117166 25173 raft_consensus.cc:2272] T 4bae55ff194f4d83acdc68cae6fb694f P 6655e200ad2a4580a61edb24e18b8258 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:54.135823 25173 tablet_server.cc:196] TabletServer@127.24.149.65:0 shutdown complete.
I20260812 06:16:55.138635 25173 master.cc:562] Master@127.24.149.126:40159 shutting down...
I20260812 06:16:55.142462 25173 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 251f5a7a16fe44acb147a3365f0f5d6d [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:55.142676 25173 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 251f5a7a16fe44acb147a3365f0f5d6d [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:55.142777 25173 tablet_replica.cc:333] T 00000000000000000000000000000000 P 251f5a7a16fe44acb147a3365f0f5d6d: stopping tablet replica
I20260812 06:16:55.155519 25173 master.cc:584] Master@127.24.149.126:40159 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (9138 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (14482 ms total)

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