[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:19:11.023373 18375 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.17.241.254:38885
I20260812 06:19:11.024453 18375 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:19:11.025066 18375 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:11.031500 18383 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:11.031563 18381 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:11.032285 18375 server_base.cc:1061] running on GCE node
W20260812 06:19:11.033205 18387 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:11.033849 18375 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:11.034036 18375 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:11.034132 18375 hybrid_clock.cc:648] HybridClock initialized: now 1786515551034128 us; error 0 us; skew 500 ppm
I20260812 06:19:11.036289 18375 webserver.cc:533] Webserver started at http://127.17.241.254:33633/ using document root <none> and password file <none>
I20260812 06:19:11.036860 18375 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:11.036950 18375 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:11.037194 18375 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:11.038901 18375 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551012943-18375-0/minicluster-data/master-0-root/instance:
uuid: "c1bee2872ab34f8bb45443a5df4d4d5b"
format_stamp: "Formatted at 2026-08-12 06:19:11 on dist-test-slave-1xrh"
I20260812 06:19:11.042340 18375 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.001s	sys 0.001s
I20260812 06:19:11.044737 18393 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:11.045715 18375 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:19:11.045843 18375 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551012943-18375-0/minicluster-data/master-0-root
uuid: "c1bee2872ab34f8bb45443a5df4d4d5b"
format_stamp: "Formatted at 2026-08-12 06:19:11 on dist-test-slave-1xrh"
I20260812 06:19:11.045948 18375 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551012943-18375-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551012943-18375-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551012943-18375-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:11.062000 18375 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:11.062625 18375 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:19:11.062798 18375 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:11.070233 18375 rpc_server.cc:307] RPC server started. Bound to: 127.17.241.254:38885
I20260812 06:19:11.070247 18451 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.17.241.254:38885 every 8 connection(s)
I20260812 06:19:11.072408 18452 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:11.077948 18452 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P c1bee2872ab34f8bb45443a5df4d4d5b: Bootstrap starting.
I20260812 06:19:11.080250 18452 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P c1bee2872ab34f8bb45443a5df4d4d5b: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:11.081077 18452 log.cc:826] T 00000000000000000000000000000000 P c1bee2872ab34f8bb45443a5df4d4d5b: Log is configured to *not* fsync() on all Append() calls
I20260812 06:19:11.082672 18452 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P c1bee2872ab34f8bb45443a5df4d4d5b: No bootstrap required, opened a new log
I20260812 06:19:11.085302 18452 raft_consensus.cc:359] T 00000000000000000000000000000000 P c1bee2872ab34f8bb45443a5df4d4d5b [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c1bee2872ab34f8bb45443a5df4d4d5b" member_type: VOTER }
I20260812 06:19:11.085457 18452 raft_consensus.cc:385] T 00000000000000000000000000000000 P c1bee2872ab34f8bb45443a5df4d4d5b [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:11.085505 18452 raft_consensus.cc:740] T 00000000000000000000000000000000 P c1bee2872ab34f8bb45443a5df4d4d5b [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: c1bee2872ab34f8bb45443a5df4d4d5b, State: Initialized, Role: FOLLOWER
I20260812 06:19:11.086081 18452 consensus_queue.cc:260] T 00000000000000000000000000000000 P c1bee2872ab34f8bb45443a5df4d4d5b [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: "c1bee2872ab34f8bb45443a5df4d4d5b" member_type: VOTER }
I20260812 06:19:11.086216 18452 raft_consensus.cc:399] T 00000000000000000000000000000000 P c1bee2872ab34f8bb45443a5df4d4d5b [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:11.086263 18452 raft_consensus.cc:493] T 00000000000000000000000000000000 P c1bee2872ab34f8bb45443a5df4d4d5b [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:11.086350 18452 raft_consensus.cc:3060] T 00000000000000000000000000000000 P c1bee2872ab34f8bb45443a5df4d4d5b [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:11.087042 18452 raft_consensus.cc:515] T 00000000000000000000000000000000 P c1bee2872ab34f8bb45443a5df4d4d5b [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c1bee2872ab34f8bb45443a5df4d4d5b" member_type: VOTER }
I20260812 06:19:11.087462 18452 leader_election.cc:304] T 00000000000000000000000000000000 P c1bee2872ab34f8bb45443a5df4d4d5b [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: c1bee2872ab34f8bb45443a5df4d4d5b; no voters: 
I20260812 06:19:11.087706 18452 leader_election.cc:290] T 00000000000000000000000000000000 P c1bee2872ab34f8bb45443a5df4d4d5b [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:11.087836 18455 raft_consensus.cc:2804] T 00000000000000000000000000000000 P c1bee2872ab34f8bb45443a5df4d4d5b [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:11.088114 18455 raft_consensus.cc:697] T 00000000000000000000000000000000 P c1bee2872ab34f8bb45443a5df4d4d5b [term 1 LEADER]: Becoming Leader. State: Replica: c1bee2872ab34f8bb45443a5df4d4d5b, State: Running, Role: LEADER
I20260812 06:19:11.088539 18455 consensus_queue.cc:237] T 00000000000000000000000000000000 P c1bee2872ab34f8bb45443a5df4d4d5b [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: "c1bee2872ab34f8bb45443a5df4d4d5b" member_type: VOTER }
I20260812 06:19:11.088629 18452 sys_catalog.cc:565] T 00000000000000000000000000000000 P c1bee2872ab34f8bb45443a5df4d4d5b [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:11.090497 18456 sys_catalog.cc:455] T 00000000000000000000000000000000 P c1bee2872ab34f8bb45443a5df4d4d5b [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "c1bee2872ab34f8bb45443a5df4d4d5b" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c1bee2872ab34f8bb45443a5df4d4d5b" member_type: VOTER } }
I20260812 06:19:11.090488 18457 sys_catalog.cc:455] T 00000000000000000000000000000000 P c1bee2872ab34f8bb45443a5df4d4d5b [sys.catalog]: SysCatalogTable state changed. Reason: New leader c1bee2872ab34f8bb45443a5df4d4d5b. Latest consensus state: current_term: 1 leader_uuid: "c1bee2872ab34f8bb45443a5df4d4d5b" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c1bee2872ab34f8bb45443a5df4d4d5b" member_type: VOTER } }
I20260812 06:19:11.090626 18456 sys_catalog.cc:458] T 00000000000000000000000000000000 P c1bee2872ab34f8bb45443a5df4d4d5b [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:11.090931 18375 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:11.090626 18457 sys_catalog.cc:458] T 00000000000000000000000000000000 P c1bee2872ab34f8bb45443a5df4d4d5b [sys.catalog]: This master's current role is: LEADER
W20260812 06:19:11.093351 18471 catalog_manager.cc:1594] T 00000000000000000000000000000000 P c1bee2872ab34f8bb45443a5df4d4d5b: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:19:11.093430 18471 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:19:11.093515 18472 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:11.094218 18472 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:11.098676 18472 catalog_manager.cc:1383] Generated new cluster ID: 473778d87d9c4b8682ea93575ba8d9df
I20260812 06:19:11.098733 18472 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:11.117259 18472 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:11.118331 18472 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:11.125324 18472 catalog_manager.cc:6092] T 00000000000000000000000000000000 P c1bee2872ab34f8bb45443a5df4d4d5b: Generated new TSK 0
I20260812 06:19:11.126031 18472 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:11.155723 18375 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:11.158299 18478 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:11.158346 18481 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:11.158584 18375 server_base.cc:1061] running on GCE node
W20260812 06:19:11.158393 18479 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:11.158870 18375 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:11.158919 18375 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:11.158936 18375 hybrid_clock.cc:648] HybridClock initialized: now 1786515551158936 us; error 0 us; skew 500 ppm
I20260812 06:19:11.159957 18375 webserver.cc:533] Webserver started at http://127.17.241.193:33603/ using document root <none> and password file <none>
I20260812 06:19:11.160132 18375 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:11.160187 18375 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:11.160279 18375 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:11.160668 18375 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551012943-18375-0/minicluster-data/ts-0-root/instance:
uuid: "c6f0c249801d47c7807a85ec9b6ff8e3"
format_stamp: "Formatted at 2026-08-12 06:19:11 on dist-test-slave-1xrh"
I20260812 06:19:11.162237 18375 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:11.163247 18487 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:11.163509 18375 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:11.163609 18375 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551012943-18375-0/minicluster-data/ts-0-root
uuid: "c6f0c249801d47c7807a85ec9b6ff8e3"
format_stamp: "Formatted at 2026-08-12 06:19:11 on dist-test-slave-1xrh"
I20260812 06:19:11.163673 18375 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551012943-18375-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551012943-18375-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551012943-18375-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:11.173053 18375 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:11.173467 18375 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:11.173928 18375 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:11.174713 18375 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:11.174780 18375 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:11.174847 18375 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:11.174889 18375 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:11.181890 18375 rpc_server.cc:307] RPC server started. Bound to: 127.17.241.193:39871
I20260812 06:19:11.181933 18563 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.17.241.193:39871 every 8 connection(s)
I20260812 06:19:11.195008 18564 heartbeater.cc:344] Connected to a master server at 127.17.241.254:38885
I20260812 06:19:11.195286 18564 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:11.195803 18564 heartbeater.cc:507] Master 127.17.241.254:38885 requested a full tablet report, sending...
I20260812 06:19:11.197240 18413 ts_manager.cc:194] Registered new tserver with Master: c6f0c249801d47c7807a85ec9b6ff8e3 (127.17.241.193:39871)
I20260812 06:19:11.198055 18375 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.015539679s
I20260812 06:19:11.198509 18413 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:58950
I20260812 06:19:11.207564 18413 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:58958:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:19:11.222177 18519 tablet_service.cc:1511] Processing CreateTablet for tablet 16dea21c233d415799fc5422284f9acc (DEFAULT_TABLE table=heavy-update-compaction-test [id=073d5993a6f14509894a8d06ffa6c0b4]), partition=
I20260812 06:19:11.222608 18519 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 16dea21c233d415799fc5422284f9acc. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:11.225401 18580 tablet_bootstrap.cc:492] T 16dea21c233d415799fc5422284f9acc P c6f0c249801d47c7807a85ec9b6ff8e3: Bootstrap starting.
I20260812 06:19:11.226398 18580 tablet_bootstrap.cc:654] T 16dea21c233d415799fc5422284f9acc P c6f0c249801d47c7807a85ec9b6ff8e3: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:11.227658 18580 tablet_bootstrap.cc:492] T 16dea21c233d415799fc5422284f9acc P c6f0c249801d47c7807a85ec9b6ff8e3: No bootstrap required, opened a new log
I20260812 06:19:11.227777 18580 ts_tablet_manager.cc:1403] T 16dea21c233d415799fc5422284f9acc P c6f0c249801d47c7807a85ec9b6ff8e3: Time spent bootstrapping tablet: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:11.228252 18580 raft_consensus.cc:359] T 16dea21c233d415799fc5422284f9acc P c6f0c249801d47c7807a85ec9b6ff8e3 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c6f0c249801d47c7807a85ec9b6ff8e3" member_type: VOTER last_known_addr { host: "127.17.241.193" port: 39871 } }
I20260812 06:19:11.228366 18580 raft_consensus.cc:385] T 16dea21c233d415799fc5422284f9acc P c6f0c249801d47c7807a85ec9b6ff8e3 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:11.228451 18580 raft_consensus.cc:740] T 16dea21c233d415799fc5422284f9acc P c6f0c249801d47c7807a85ec9b6ff8e3 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: c6f0c249801d47c7807a85ec9b6ff8e3, State: Initialized, Role: FOLLOWER
I20260812 06:19:11.228605 18580 consensus_queue.cc:260] T 16dea21c233d415799fc5422284f9acc P c6f0c249801d47c7807a85ec9b6ff8e3 [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: "c6f0c249801d47c7807a85ec9b6ff8e3" member_type: VOTER last_known_addr { host: "127.17.241.193" port: 39871 } }
I20260812 06:19:11.228710 18580 raft_consensus.cc:399] T 16dea21c233d415799fc5422284f9acc P c6f0c249801d47c7807a85ec9b6ff8e3 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:11.228765 18580 raft_consensus.cc:493] T 16dea21c233d415799fc5422284f9acc P c6f0c249801d47c7807a85ec9b6ff8e3 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:11.228827 18580 raft_consensus.cc:3060] T 16dea21c233d415799fc5422284f9acc P c6f0c249801d47c7807a85ec9b6ff8e3 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:11.229553 18580 raft_consensus.cc:515] T 16dea21c233d415799fc5422284f9acc P c6f0c249801d47c7807a85ec9b6ff8e3 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c6f0c249801d47c7807a85ec9b6ff8e3" member_type: VOTER last_known_addr { host: "127.17.241.193" port: 39871 } }
I20260812 06:19:11.229701 18580 leader_election.cc:304] T 16dea21c233d415799fc5422284f9acc P c6f0c249801d47c7807a85ec9b6ff8e3 [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: c6f0c249801d47c7807a85ec9b6ff8e3; no voters: 
I20260812 06:19:11.229923 18580 leader_election.cc:290] T 16dea21c233d415799fc5422284f9acc P c6f0c249801d47c7807a85ec9b6ff8e3 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:11.230088 18584 raft_consensus.cc:2804] T 16dea21c233d415799fc5422284f9acc P c6f0c249801d47c7807a85ec9b6ff8e3 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:11.230401 18584 raft_consensus.cc:697] T 16dea21c233d415799fc5422284f9acc P c6f0c249801d47c7807a85ec9b6ff8e3 [term 1 LEADER]: Becoming Leader. State: Replica: c6f0c249801d47c7807a85ec9b6ff8e3, State: Running, Role: LEADER
I20260812 06:19:11.230520 18564 heartbeater.cc:499] Master 127.17.241.254:38885 was elected leader, sending a full tablet report...
I20260812 06:19:11.230554 18584 consensus_queue.cc:237] T 16dea21c233d415799fc5422284f9acc P c6f0c249801d47c7807a85ec9b6ff8e3 [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: "c6f0c249801d47c7807a85ec9b6ff8e3" member_type: VOTER last_known_addr { host: "127.17.241.193" port: 39871 } }
I20260812 06:19:11.230273 18580 ts_tablet_manager.cc:1434] T 16dea21c233d415799fc5422284f9acc P c6f0c249801d47c7807a85ec9b6ff8e3: Time spent starting tablet: real 0.002s	user 0.003s	sys 0.000s
I20260812 06:19:11.233173 18413 catalog_manager.cc:5719] T 16dea21c233d415799fc5422284f9acc P c6f0c249801d47c7807a85ec9b6ff8e3 reported cstate change: term changed from 0 to 1, leader changed from <none> to c6f0c249801d47c7807a85ec9b6ff8e3 (127.17.241.193). New cstate: current_term: 1 leader_uuid: "c6f0c249801d47c7807a85ec9b6ff8e3" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c6f0c249801d47c7807a85ec9b6ff8e3" member_type: VOTER last_known_addr { host: "127.17.241.193" port: 39871 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:11.302098 18375 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.063s	user 0.024s	sys 0.008s
I20260812 06:19:11.433161 18565 maintenance_manager.cc:419] P c6f0c249801d47c7807a85ec9b6ff8e3: Scheduling FlushMRSOp(16dea21c233d415799fc5422284f9acc): perf score=15.086190
I20260812 06:19:11.622285 18492 maintenance_manager.cc:643] P c6f0c249801d47c7807a85ec9b6ff8e3: FlushMRSOp(16dea21c233d415799fc5422284f9acc) complete. Timing: real 0.189s	user 0.144s	sys 0.031s Metrics: {"bytes_written":15999661,"cfile_init":1,"compiler_manager_pool.queue_time_us":239,"delete_count":0,"dirs.queue_time_us":78,"dirs.run_cpu_time_us":229,"dirs.run_wall_time_us":882,"drs_written":1,"lbm_read_time_us":83,"lbm_reads_lt_1ms":4,"lbm_write_time_us":46923,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"thread_start_us":151,"threads_started":1,"update_count":1950}
I20260812 06:19:11.623873 18565 maintenance_manager.cc:419] P c6f0c249801d47c7807a85ec9b6ff8e3: Scheduling LogGCOp(16dea21c233d415799fc5422284f9acc): free 20743880 bytes of WAL
I20260812 06:19:11.624265 18492 log_reader.cc:385] T 16dea21c233d415799fc5422284f9acc: removed 2 log segments from log reader
I20260812 06:19:11.624393 18492 log.cc:1079] T 16dea21c233d415799fc5422284f9acc P c6f0c249801d47c7807a85ec9b6ff8e3: Deleting log segment in path: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551012943-18375-0/minicluster-data/ts-0-root/wals/16dea21c233d415799fc5422284f9acc/wal-000000001 (ops 1-6)
I20260812 06:19:11.624503 18492 log.cc:1079] T 16dea21c233d415799fc5422284f9acc P c6f0c249801d47c7807a85ec9b6ff8e3: Deleting log segment in path: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551012943-18375-0/minicluster-data/ts-0-root/wals/16dea21c233d415799fc5422284f9acc/wal-000000002 (ops 7-11)
I20260812 06:19:11.630681 18492 maintenance_manager.cc:643] P c6f0c249801d47c7807a85ec9b6ff8e3: LogGCOp(16dea21c233d415799fc5422284f9acc) complete. Timing: real 0.007s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:19:11.631182 18565 maintenance_manager.cc:419] P c6f0c249801d47c7807a85ec9b6ff8e3: Scheduling UndoDeltaBlockGCOp(16dea21c233d415799fc5422284f9acc): 12719217 bytes on disk
I20260812 06:19:11.631990 18492 maintenance_manager.cc:643] P c6f0c249801d47c7807a85ec9b6ff8e3: UndoDeltaBlockGCOp(16dea21c233d415799fc5422284f9acc) complete. Timing: real 0.001s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":80,"lbm_reads_lt_1ms":4}
I20260812 06:19:11.632542 18565 maintenance_manager.cc:419] P c6f0c249801d47c7807a85ec9b6ff8e3: Scheduling FlushDeltaMemStoresOp(16dea21c233d415799fc5422284f9acc): perf score=2.188937
I20260812 06:19:11.662909 18492 maintenance_manager.cc:643] P c6f0c249801d47c7807a85ec9b6ff8e3: FlushDeltaMemStoresOp(16dea21c233d415799fc5422284f9acc) complete. Timing: real 0.030s	user 0.009s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5767,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:11.663388 18565 maintenance_manager.cc:419] P c6f0c249801d47c7807a85ec9b6ff8e3: Scheduling FlushDeltaMemStoresOp(16dea21c233d415799fc5422284f9acc): perf score=2.188937
I20260812 06:19:11.674080 18492 maintenance_manager.cc:643] P c6f0c249801d47c7807a85ec9b6ff8e3: FlushDeltaMemStoresOp(16dea21c233d415799fc5422284f9acc) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4444,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:11.674523 18565 maintenance_manager.cc:419] P c6f0c249801d47c7807a85ec9b6ff8e3: Scheduling MajorDeltaCompactionOp(16dea21c233d415799fc5422284f9acc): perf score=1.000000
I20260812 06:19:11.878508 18492 maintenance_manager.cc:643] P c6f0c249801d47c7807a85ec9b6ff8e3: MajorDeltaCompactionOp(16dea21c233d415799fc5422284f9acc) complete. Timing: real 0.204s	user 0.143s	sys 0.056s Metrics: {"cfile_cache_miss":623,"cfile_cache_miss_bytes":28466979,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":832,"lbm_read_time_us":16274,"lbm_reads_lt_1ms":659,"lbm_write_time_us":36347,"lbm_writes_lt_1ms":633,"mutex_wait_us":32,"peak_mem_usage":74091738,"reinsert_count":0,"thread_start_us":319,"threads_started":5,"update_count":2950}
I20260812 06:19:11.879035 18565 maintenance_manager.cc:419] P c6f0c249801d47c7807a85ec9b6ff8e3: Scheduling FlushDeltaMemStoresOp(16dea21c233d415799fc5422284f9acc): perf score=11.118625
I20260812 06:19:11.919327 18492 maintenance_manager.cc:643] P c6f0c249801d47c7807a85ec9b6ff8e3: FlushDeltaMemStoresOp(16dea21c233d415799fc5422284f9acc) complete. Timing: real 0.040s	user 0.023s	sys 0.017s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":17359,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:11.919917 18565 maintenance_manager.cc:419] P c6f0c249801d47c7807a85ec9b6ff8e3: Scheduling FlushDeltaMemStoresOp(16dea21c233d415799fc5422284f9acc): perf score=2.188937
I20260812 06:19:11.947077 18492 maintenance_manager.cc:643] P c6f0c249801d47c7807a85ec9b6ff8e3: FlushDeltaMemStoresOp(16dea21c233d415799fc5422284f9acc) complete. Timing: real 0.027s	user 0.010s	sys 0.011s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5433,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:11.947598 18565 maintenance_manager.cc:419] P c6f0c249801d47c7807a85ec9b6ff8e3: Scheduling MajorDeltaCompactionOp(16dea21c233d415799fc5422284f9acc): perf score=1.000000
I20260812 06:19:12.094215 18492 maintenance_manager.cc:643] P c6f0c249801d47c7807a85ec9b6ff8e3: MajorDeltaCompactionOp(16dea21c233d415799fc5422284f9acc) complete. Timing: real 0.146s	user 0.110s	sys 0.037s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":269,"lbm_read_time_us":9519,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24118,"lbm_writes_lt_1ms":443,"mutex_wait_us":40,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9344,"update_count":2000}
I20260812 06:19:12.094798 18565 maintenance_manager.cc:419] P c6f0c249801d47c7807a85ec9b6ff8e3: Scheduling FlushDeltaMemStoresOp(16dea21c233d415799fc5422284f9acc): perf score=11.118625
I20260812 06:19:12.129206 18492 maintenance_manager.cc:643] P c6f0c249801d47c7807a85ec9b6ff8e3: FlushDeltaMemStoresOp(16dea21c233d415799fc5422284f9acc) complete. Timing: real 0.034s	user 0.025s	sys 0.008s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":14687,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:12.129892 18565 maintenance_manager.cc:419] P c6f0c249801d47c7807a85ec9b6ff8e3: Scheduling FlushDeltaMemStoresOp(16dea21c233d415799fc5422284f9acc): perf score=2.188937
I20260812 06:19:12.152717 18492 maintenance_manager.cc:643] P c6f0c249801d47c7807a85ec9b6ff8e3: FlushDeltaMemStoresOp(16dea21c233d415799fc5422284f9acc) complete. Timing: real 0.023s	user 0.011s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4992,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:12.153141 18565 maintenance_manager.cc:419] P c6f0c249801d47c7807a85ec9b6ff8e3: Scheduling FlushDeltaMemStoresOp(16dea21c233d415799fc5422284f9acc): perf score=2.188937
I20260812 06:19:12.163146 18492 maintenance_manager.cc:643] P c6f0c249801d47c7807a85ec9b6ff8e3: FlushDeltaMemStoresOp(16dea21c233d415799fc5422284f9acc) complete. Timing: real 0.010s	user 0.005s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4066,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:12.163578 18565 maintenance_manager.cc:419] P c6f0c249801d47c7807a85ec9b6ff8e3: Scheduling MajorDeltaCompactionOp(16dea21c233d415799fc5422284f9acc): perf score=1.000000
I20260812 06:19:12.326457 18492 maintenance_manager.cc:643] P c6f0c249801d47c7807a85ec9b6ff8e3: MajorDeltaCompactionOp(16dea21c233d415799fc5422284f9acc) complete. Timing: real 0.163s	user 0.134s	sys 0.028s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774799,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":155,"lbm_read_time_us":11567,"lbm_reads_lt_1ms":573,"lbm_write_time_us":35319,"lbm_writes_lt_1ms":543,"mutex_wait_us":35,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:12.327427 18565 maintenance_manager.cc:419] P c6f0c249801d47c7807a85ec9b6ff8e3: Scheduling FlushDeltaMemStoresOp(16dea21c233d415799fc5422284f9acc): perf score=11.118625
I20260812 06:19:12.362712 18492 maintenance_manager.cc:643] P c6f0c249801d47c7807a85ec9b6ff8e3: FlushDeltaMemStoresOp(16dea21c233d415799fc5422284f9acc) complete. Timing: real 0.035s	user 0.023s	sys 0.009s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":14734,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:12.363354 18565 maintenance_manager.cc:419] P c6f0c249801d47c7807a85ec9b6ff8e3: Scheduling FlushDeltaMemStoresOp(16dea21c233d415799fc5422284f9acc): perf score=2.188937
I20260812 06:19:12.391273 18492 maintenance_manager.cc:643] P c6f0c249801d47c7807a85ec9b6ff8e3: FlushDeltaMemStoresOp(16dea21c233d415799fc5422284f9acc) complete. Timing: real 0.028s	user 0.010s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5547,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:12.391739 18565 maintenance_manager.cc:419] P c6f0c249801d47c7807a85ec9b6ff8e3: Scheduling FlushDeltaMemStoresOp(16dea21c233d415799fc5422284f9acc): perf score=2.188937
I20260812 06:19:12.405973 18492 maintenance_manager.cc:643] P c6f0c249801d47c7807a85ec9b6ff8e3: FlushDeltaMemStoresOp(16dea21c233d415799fc5422284f9acc) complete. Timing: real 0.014s	user 0.001s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5742,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:12.406452 18565 maintenance_manager.cc:419] P c6f0c249801d47c7807a85ec9b6ff8e3: Scheduling MajorDeltaCompactionOp(16dea21c233d415799fc5422284f9acc): perf score=1.000000
I20260812 06:19:12.566017 18492 maintenance_manager.cc:643] P c6f0c249801d47c7807a85ec9b6ff8e3: MajorDeltaCompactionOp(16dea21c233d415799fc5422284f9acc) complete. Timing: real 0.159s	user 0.121s	sys 0.028s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774800,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":138,"lbm_read_time_us":11685,"lbm_reads_lt_1ms":573,"lbm_write_time_us":30536,"lbm_writes_lt_1ms":543,"mutex_wait_us":40,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7296,"update_count":2500}
I20260812 06:19:12.566483 18565 maintenance_manager.cc:419] P c6f0c249801d47c7807a85ec9b6ff8e3: Scheduling FlushDeltaMemStoresOp(16dea21c233d415799fc5422284f9acc): perf score=14.095187
I20260812 06:19:12.616250 18492 maintenance_manager.cc:643] P c6f0c249801d47c7807a85ec9b6ff8e3: FlushDeltaMemStoresOp(16dea21c233d415799fc5422284f9acc) complete. Timing: real 0.050s	user 0.037s	sys 0.011s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":21754,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:12.616772 18565 maintenance_manager.cc:419] P c6f0c249801d47c7807a85ec9b6ff8e3: Scheduling FlushDeltaMemStoresOp(16dea21c233d415799fc5422284f9acc): perf score=2.188937
I20260812 06:19:12.632476 18492 maintenance_manager.cc:643] P c6f0c249801d47c7807a85ec9b6ff8e3: FlushDeltaMemStoresOp(16dea21c233d415799fc5422284f9acc) complete. Timing: real 0.016s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5829,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:12.632936 18565 maintenance_manager.cc:419] P c6f0c249801d47c7807a85ec9b6ff8e3: Scheduling MajorDeltaCompactionOp(16dea21c233d415799fc5422284f9acc): perf score=1.000000
I20260812 06:19:12.804693 18492 maintenance_manager.cc:643] P c6f0c249801d47c7807a85ec9b6ff8e3: MajorDeltaCompactionOp(16dea21c233d415799fc5422284f9acc) complete. Timing: real 0.172s	user 0.117s	sys 0.044s 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":1022,"lbm_read_time_us":10922,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31847,"lbm_writes_lt_1ms":543,"mutex_wait_us":359,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6656,"update_count":2500}
I20260812 06:19:12.805459 18565 maintenance_manager.cc:419] P c6f0c249801d47c7807a85ec9b6ff8e3: Scheduling FlushDeltaMemStoresOp(16dea21c233d415799fc5422284f9acc): perf score=14.095187
I20260812 06:19:12.868981 18492 maintenance_manager.cc:643] P c6f0c249801d47c7807a85ec9b6ff8e3: FlushDeltaMemStoresOp(16dea21c233d415799fc5422284f9acc) complete. Timing: real 0.063s	user 0.029s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22683,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:12.869472 18565 maintenance_manager.cc:419] P c6f0c249801d47c7807a85ec9b6ff8e3: Scheduling FlushDeltaMemStoresOp(16dea21c233d415799fc5422284f9acc): perf score=2.188937
I20260812 06:19:12.881003 18492 maintenance_manager.cc:643] P c6f0c249801d47c7807a85ec9b6ff8e3: FlushDeltaMemStoresOp(16dea21c233d415799fc5422284f9acc) complete. Timing: real 0.011s	user 0.008s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4160,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:12.881480 18565 maintenance_manager.cc:419] P c6f0c249801d47c7807a85ec9b6ff8e3: Scheduling FlushMRSOp(16dea21c233d415799fc5422284f9acc): perf score=1.000000
I20260812 06:19:12.907532 18492 maintenance_manager.cc:643] P c6f0c249801d47c7807a85ec9b6ff8e3: FlushMRSOp(16dea21c233d415799fc5422284f9acc) complete. Timing: real 0.026s	user 0.020s	sys 0.005s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":55,"dirs.run_cpu_time_us":242,"dirs.run_wall_time_us":1393,"drs_written":1,"lbm_read_time_us":36,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1451,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:12.908454 18565 maintenance_manager.cc:419] P c6f0c249801d47c7807a85ec9b6ff8e3: Scheduling LogGCOp(16dea21c233d415799fc5422284f9acc): free 112239265 bytes of WAL
I20260812 06:19:12.908710 18492 log_reader.cc:385] T 16dea21c233d415799fc5422284f9acc: removed 11 log segments from log reader
I20260812 06:19:12.908757 18492 log.cc:1079] T 16dea21c233d415799fc5422284f9acc P c6f0c249801d47c7807a85ec9b6ff8e3: Deleting log segment in path: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551012943-18375-0/minicluster-data/ts-0-root/wals/16dea21c233d415799fc5422284f9acc/wal-000000003 (ops 12-16)
I20260812 06:19:12.908787 18492 log.cc:1079] T 16dea21c233d415799fc5422284f9acc P c6f0c249801d47c7807a85ec9b6ff8e3: Deleting log segment in path: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551012943-18375-0/minicluster-data/ts-0-root/wals/16dea21c233d415799fc5422284f9acc/wal-000000004 (ops 17-21)
I20260812 06:19:12.908803 18492 log.cc:1079] T 16dea21c233d415799fc5422284f9acc P c6f0c249801d47c7807a85ec9b6ff8e3: Deleting log segment in path: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551012943-18375-0/minicluster-data/ts-0-root/wals/16dea21c233d415799fc5422284f9acc/wal-000000005 (ops 22-26)
I20260812 06:19:12.908862 18492 log.cc:1079] T 16dea21c233d415799fc5422284f9acc P c6f0c249801d47c7807a85ec9b6ff8e3: Deleting log segment in path: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551012943-18375-0/minicluster-data/ts-0-root/wals/16dea21c233d415799fc5422284f9acc/wal-000000006 (ops 27-30)
I20260812 06:19:12.908921 18492 log.cc:1079] T 16dea21c233d415799fc5422284f9acc P c6f0c249801d47c7807a85ec9b6ff8e3: Deleting log segment in path: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551012943-18375-0/minicluster-data/ts-0-root/wals/16dea21c233d415799fc5422284f9acc/wal-000000007 (ops 31-35)
I20260812 06:19:12.908965 18492 log.cc:1079] T 16dea21c233d415799fc5422284f9acc P c6f0c249801d47c7807a85ec9b6ff8e3: Deleting log segment in path: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551012943-18375-0/minicluster-data/ts-0-root/wals/16dea21c233d415799fc5422284f9acc/wal-000000008 (ops 36-40)
I20260812 06:19:12.909017 18492 log.cc:1079] T 16dea21c233d415799fc5422284f9acc P c6f0c249801d47c7807a85ec9b6ff8e3: Deleting log segment in path: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551012943-18375-0/minicluster-data/ts-0-root/wals/16dea21c233d415799fc5422284f9acc/wal-000000009 (ops 41-45)
I20260812 06:19:12.909068 18492 log.cc:1079] T 16dea21c233d415799fc5422284f9acc P c6f0c249801d47c7807a85ec9b6ff8e3: Deleting log segment in path: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551012943-18375-0/minicluster-data/ts-0-root/wals/16dea21c233d415799fc5422284f9acc/wal-000000010 (ops 46-50)
I20260812 06:19:12.909102 18492 log.cc:1079] T 16dea21c233d415799fc5422284f9acc P c6f0c249801d47c7807a85ec9b6ff8e3: Deleting log segment in path: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551012943-18375-0/minicluster-data/ts-0-root/wals/16dea21c233d415799fc5422284f9acc/wal-000000011 (ops 51-55)
I20260812 06:19:12.909152 18492 log.cc:1079] T 16dea21c233d415799fc5422284f9acc P c6f0c249801d47c7807a85ec9b6ff8e3: Deleting log segment in path: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551012943-18375-0/minicluster-data/ts-0-root/wals/16dea21c233d415799fc5422284f9acc/wal-000000012 (ops 56-60)
I20260812 06:19:12.909190 18492 log.cc:1079] T 16dea21c233d415799fc5422284f9acc P c6f0c249801d47c7807a85ec9b6ff8e3: Deleting log segment in path: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551012943-18375-0/minicluster-data/ts-0-root/wals/16dea21c233d415799fc5422284f9acc/wal-000000013 (ops 61-65)
I20260812 06:19:12.935186 18492 maintenance_manager.cc:643] P c6f0c249801d47c7807a85ec9b6ff8e3: LogGCOp(16dea21c233d415799fc5422284f9acc) complete. Timing: real 0.026s	user 0.000s	sys 0.023s Metrics: {}
I20260812 06:19:12.936352 18565 maintenance_manager.cc:419] P c6f0c249801d47c7807a85ec9b6ff8e3: Scheduling UndoDeltaBlockGCOp(16dea21c233d415799fc5422284f9acc): 462 bytes on disk
I20260812 06:19:12.936946 18492 maintenance_manager.cc:643] P c6f0c249801d47c7807a85ec9b6ff8e3: UndoDeltaBlockGCOp(16dea21c233d415799fc5422284f9acc) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":67,"lbm_reads_lt_1ms":4}
I20260812 06:19:12.937494 18565 maintenance_manager.cc:419] P c6f0c249801d47c7807a85ec9b6ff8e3: Scheduling FlushDeltaMemStoresOp(16dea21c233d415799fc5422284f9acc): perf score=3.181125
I20260812 06:19:12.955552 18492 maintenance_manager.cc:643] P c6f0c249801d47c7807a85ec9b6ff8e3: FlushDeltaMemStoresOp(16dea21c233d415799fc5422284f9acc) complete. Timing: real 0.018s	user 0.009s	sys 0.008s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":7413,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:12.955955 18565 maintenance_manager.cc:419] P c6f0c249801d47c7807a85ec9b6ff8e3: Scheduling FlushDeltaMemStoresOp(16dea21c233d415799fc5422284f9acc): perf score=2.188937
I20260812 06:19:12.965780 18492 maintenance_manager.cc:643] P c6f0c249801d47c7807a85ec9b6ff8e3: FlushDeltaMemStoresOp(16dea21c233d415799fc5422284f9acc) complete. Timing: real 0.010s	user 0.004s	sys 0.003s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3861,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:12.966189 18565 maintenance_manager.cc:419] P c6f0c249801d47c7807a85ec9b6ff8e3: Scheduling MajorDeltaCompactionOp(16dea21c233d415799fc5422284f9acc): perf score=1.000000
I20260812 06:19:13.187592 18492 maintenance_manager.cc:643] P c6f0c249801d47c7807a85ec9b6ff8e3: MajorDeltaCompactionOp(16dea21c233d415799fc5422284f9acc) complete. Timing: real 0.221s	user 0.126s	sys 0.093s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979737,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":800,"lbm_read_time_us":16817,"lbm_reads_lt_1ms":774,"lbm_write_time_us":42736,"lbm_writes_lt_1ms":743,"mutex_wait_us":333,"peak_mem_usage":87969044,"reinsert_count":0,"thread_start_us":81,"threads_started":1,"update_count":3500}
I20260812 06:19:13.188246 18565 maintenance_manager.cc:419] P c6f0c249801d47c7807a85ec9b6ff8e3: Scheduling FlushDeltaMemStoresOp(16dea21c233d415799fc5422284f9acc): perf score=15.087375
I20260812 06:19:13.256146 18492 maintenance_manager.cc:643] P c6f0c249801d47c7807a85ec9b6ff8e3: FlushDeltaMemStoresOp(16dea21c233d415799fc5422284f9acc) complete. Timing: real 0.068s	user 0.038s	sys 0.024s Metrics: {"bytes_written":16820142,"delete_count":0,"lbm_write_time_us":28517,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":412,"reinsert_count":0,"update_count":2050}
I20260812 06:19:13.256606 18565 maintenance_manager.cc:419] P c6f0c249801d47c7807a85ec9b6ff8e3: Scheduling FlushDeltaMemStoresOp(16dea21c233d415799fc5422284f9acc): perf score=6.157687
I20260812 06:19:13.281999 18492 maintenance_manager.cc:643] P c6f0c249801d47c7807a85ec9b6ff8e3: FlushDeltaMemStoresOp(16dea21c233d415799fc5422284f9acc) complete. Timing: real 0.025s	user 0.007s	sys 0.012s Metrics: {"bytes_written":7794837,"delete_count":0,"lbm_write_time_us":9466,"lbm_writes_lt_1ms":193,"reinsert_count":0,"update_count":950}
I20260812 06:19:13.282521 18565 maintenance_manager.cc:419] P c6f0c249801d47c7807a85ec9b6ff8e3: Scheduling MajorDeltaCompactionOp(16dea21c233d415799fc5422284f9acc): perf score=1.000000
I20260812 06:19:13.452482 18492 maintenance_manager.cc:643] P c6f0c249801d47c7807a85ec9b6ff8e3: MajorDeltaCompactionOp(16dea21c233d415799fc5422284f9acc) complete. Timing: real 0.170s	user 0.129s	sys 0.040s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877101,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":139,"lbm_read_time_us":14616,"lbm_reads_lt_1ms":664,"lbm_write_time_us":33438,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":3000}
I20260812 06:19:13.453122 18565 maintenance_manager.cc:419] P c6f0c249801d47c7807a85ec9b6ff8e3: Scheduling FlushDeltaMemStoresOp(16dea21c233d415799fc5422284f9acc): perf score=14.095187
I20260812 06:19:13.506974 18492 maintenance_manager.cc:643] P c6f0c249801d47c7807a85ec9b6ff8e3: FlushDeltaMemStoresOp(16dea21c233d415799fc5422284f9acc) complete. Timing: real 0.051s	user 0.035s	sys 0.013s Metrics: {"bytes_written":16820142,"delete_count":0,"lbm_write_time_us":22448,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:19:13.507607 18565 maintenance_manager.cc:419] P c6f0c249801d47c7807a85ec9b6ff8e3: Scheduling FlushDeltaMemStoresOp(16dea21c233d415799fc5422284f9acc): perf score=2.188937
I20260812 06:19:13.518927 18492 maintenance_manager.cc:643] P c6f0c249801d47c7807a85ec9b6ff8e3: FlushDeltaMemStoresOp(16dea21c233d415799fc5422284f9acc) complete. Timing: real 0.011s	user 0.000s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4097,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:13.519410 18565 maintenance_manager.cc:419] P c6f0c249801d47c7807a85ec9b6ff8e3: Scheduling MajorDeltaCompactionOp(16dea21c233d415799fc5422284f9acc): perf score=1.000000
I20260812 06:19:13.685559 18492 maintenance_manager.cc:643] P c6f0c249801d47c7807a85ec9b6ff8e3: MajorDeltaCompactionOp(16dea21c233d415799fc5422284f9acc) complete. Timing: real 0.166s	user 0.112s	sys 0.051s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774675,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":390,"lbm_read_time_us":10301,"lbm_reads_lt_1ms":564,"lbm_write_time_us":31426,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:13.686170 18565 maintenance_manager.cc:419] P c6f0c249801d47c7807a85ec9b6ff8e3: Scheduling FlushDeltaMemStoresOp(16dea21c233d415799fc5422284f9acc): perf score=14.095187
I20260812 06:19:13.745087 18492 maintenance_manager.cc:643] P c6f0c249801d47c7807a85ec9b6ff8e3: FlushDeltaMemStoresOp(16dea21c233d415799fc5422284f9acc) complete. Timing: real 0.059s	user 0.040s	sys 0.011s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24020,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:13.745605 18565 maintenance_manager.cc:419] P c6f0c249801d47c7807a85ec9b6ff8e3: Scheduling MajorDeltaCompactionOp(16dea21c233d415799fc5422284f9acc): perf score=1.000000
I20260812 06:19:13.889460 18492 maintenance_manager.cc:643] P c6f0c249801d47c7807a85ec9b6ff8e3: MajorDeltaCompactionOp(16dea21c233d415799fc5422284f9acc) complete. Timing: real 0.144s	user 0.083s	sys 0.060s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672157,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":967,"lbm_read_time_us":11274,"lbm_reads_lt_1ms":463,"lbm_write_time_us":23724,"lbm_writes_lt_1ms":443,"mutex_wait_us":291,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6528,"update_count":2000}
I20260812 06:19:13.889943 18565 maintenance_manager.cc:419] P c6f0c249801d47c7807a85ec9b6ff8e3: Scheduling FlushDeltaMemStoresOp(16dea21c233d415799fc5422284f9acc): perf score=14.095187
I20260812 06:19:13.937328 18492 maintenance_manager.cc:643] P c6f0c249801d47c7807a85ec9b6ff8e3: FlushDeltaMemStoresOp(16dea21c233d415799fc5422284f9acc) complete. Timing: real 0.047s	user 0.018s	sys 0.023s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":19450,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:13.937922 18565 maintenance_manager.cc:419] P c6f0c249801d47c7807a85ec9b6ff8e3: Scheduling FlushDeltaMemStoresOp(16dea21c233d415799fc5422284f9acc): perf score=2.188937
I20260812 06:19:13.953506 18492 maintenance_manager.cc:643] P c6f0c249801d47c7807a85ec9b6ff8e3: FlushDeltaMemStoresOp(16dea21c233d415799fc5422284f9acc) complete. Timing: real 0.015s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5955,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:13.954079 18565 maintenance_manager.cc:419] P c6f0c249801d47c7807a85ec9b6ff8e3: Scheduling MajorDeltaCompactionOp(16dea21c233d415799fc5422284f9acc): perf score=1.000000
I20260812 06:19:14.137348 18492 maintenance_manager.cc:643] P c6f0c249801d47c7807a85ec9b6ff8e3: MajorDeltaCompactionOp(16dea21c233d415799fc5422284f9acc) complete. Timing: real 0.183s	user 0.128s	sys 0.050s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":189,"lbm_read_time_us":11747,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30032,"lbm_writes_lt_1ms":543,"mutex_wait_us":19,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9600,"update_count":2500}
I20260812 06:19:14.137920 18565 maintenance_manager.cc:419] P c6f0c249801d47c7807a85ec9b6ff8e3: Scheduling FlushDeltaMemStoresOp(16dea21c233d415799fc5422284f9acc): perf score=11.118625
I20260812 06:19:14.179365 18492 maintenance_manager.cc:643] P c6f0c249801d47c7807a85ec9b6ff8e3: FlushDeltaMemStoresOp(16dea21c233d415799fc5422284f9acc) complete. Timing: real 0.041s	user 0.029s	sys 0.012s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":18581,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:14.179874 18565 maintenance_manager.cc:419] P c6f0c249801d47c7807a85ec9b6ff8e3: Scheduling FlushDeltaMemStoresOp(16dea21c233d415799fc5422284f9acc): perf score=2.188937
I20260812 06:19:14.189733 18492 maintenance_manager.cc:643] P c6f0c249801d47c7807a85ec9b6ff8e3: FlushDeltaMemStoresOp(16dea21c233d415799fc5422284f9acc) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3849,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:14.190388 18565 maintenance_manager.cc:419] P c6f0c249801d47c7807a85ec9b6ff8e3: Scheduling MajorDeltaCompactionOp(16dea21c233d415799fc5422284f9acc): perf score=1.000000
I20260812 06:19:14.321818 18492 maintenance_manager.cc:643] P c6f0c249801d47c7807a85ec9b6ff8e3: MajorDeltaCompactionOp(16dea21c233d415799fc5422284f9acc) complete. Timing: real 0.131s	user 0.099s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672269,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":260,"lbm_read_time_us":10319,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25731,"lbm_writes_lt_1ms":443,"mutex_wait_us":52,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3840,"update_count":2000}
I20260812 06:19:14.322440 18565 maintenance_manager.cc:419] P c6f0c249801d47c7807a85ec9b6ff8e3: Scheduling FlushDeltaMemStoresOp(16dea21c233d415799fc5422284f9acc): perf score=10.126437
I20260812 06:19:14.361614 18492 maintenance_manager.cc:643] P c6f0c249801d47c7807a85ec9b6ff8e3: FlushDeltaMemStoresOp(16dea21c233d415799fc5422284f9acc) complete. Timing: real 0.039s	user 0.024s	sys 0.008s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":15401,"lbm_writes_lt_1ms":303,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":1500}
I20260812 06:19:14.362133 18565 maintenance_manager.cc:419] P c6f0c249801d47c7807a85ec9b6ff8e3: Scheduling FlushDeltaMemStoresOp(16dea21c233d415799fc5422284f9acc): perf score=2.188937
I20260812 06:19:14.373612 18492 maintenance_manager.cc:643] P c6f0c249801d47c7807a85ec9b6ff8e3: FlushDeltaMemStoresOp(16dea21c233d415799fc5422284f9acc) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4374,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:14.374147 18565 maintenance_manager.cc:419] P c6f0c249801d47c7807a85ec9b6ff8e3: Scheduling FlushMRSOp(16dea21c233d415799fc5422284f9acc): perf score=1.000000
I20260812 06:19:14.402529 18492 maintenance_manager.cc:643] P c6f0c249801d47c7807a85ec9b6ff8e3: FlushMRSOp(16dea21c233d415799fc5422284f9acc) complete. Timing: real 0.028s	user 0.027s	sys 0.000s Metrics: {"bytes_written":1234479,"cfile_init":1,"dirs.queue_time_us":53,"dirs.run_cpu_time_us":193,"dirs.run_wall_time_us":1837,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1927,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:19:14.403434 18565 maintenance_manager.cc:419] P c6f0c249801d47c7807a85ec9b6ff8e3: Scheduling LogGCOp(16dea21c233d415799fc5422284f9acc): free 133024419 bytes of WAL
I20260812 06:19:14.403687 18492 log_reader.cc:385] T 16dea21c233d415799fc5422284f9acc: removed 13 log segments from log reader
I20260812 06:19:14.403765 18492 log.cc:1079] T 16dea21c233d415799fc5422284f9acc P c6f0c249801d47c7807a85ec9b6ff8e3: Deleting log segment in path: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551012943-18375-0/minicluster-data/ts-0-root/wals/16dea21c233d415799fc5422284f9acc/wal-000000014 (ops 66-70)
I20260812 06:19:14.403827 18492 log.cc:1079] T 16dea21c233d415799fc5422284f9acc P c6f0c249801d47c7807a85ec9b6ff8e3: Deleting log segment in path: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551012943-18375-0/minicluster-data/ts-0-root/wals/16dea21c233d415799fc5422284f9acc/wal-000000015 (ops 71-74)
I20260812 06:19:14.403883 18492 log.cc:1079] T 16dea21c233d415799fc5422284f9acc P c6f0c249801d47c7807a85ec9b6ff8e3: Deleting log segment in path: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551012943-18375-0/minicluster-data/ts-0-root/wals/16dea21c233d415799fc5422284f9acc/wal-000000016 (ops 75-79)
I20260812 06:19:14.403925 18492 log.cc:1079] T 16dea21c233d415799fc5422284f9acc P c6f0c249801d47c7807a85ec9b6ff8e3: Deleting log segment in path: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551012943-18375-0/minicluster-data/ts-0-root/wals/16dea21c233d415799fc5422284f9acc/wal-000000017 (ops 80-84)
I20260812 06:19:14.403962 18492 log.cc:1079] T 16dea21c233d415799fc5422284f9acc P c6f0c249801d47c7807a85ec9b6ff8e3: Deleting log segment in path: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551012943-18375-0/minicluster-data/ts-0-root/wals/16dea21c233d415799fc5422284f9acc/wal-000000018 (ops 85-89)
I20260812 06:19:14.404003 18492 log.cc:1079] T 16dea21c233d415799fc5422284f9acc P c6f0c249801d47c7807a85ec9b6ff8e3: Deleting log segment in path: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551012943-18375-0/minicluster-data/ts-0-root/wals/16dea21c233d415799fc5422284f9acc/wal-000000019 (ops 90-94)
I20260812 06:19:14.404042 18492 log.cc:1079] T 16dea21c233d415799fc5422284f9acc P c6f0c249801d47c7807a85ec9b6ff8e3: Deleting log segment in path: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551012943-18375-0/minicluster-data/ts-0-root/wals/16dea21c233d415799fc5422284f9acc/wal-000000020 (ops 95-99)
I20260812 06:19:14.404083 18492 log.cc:1079] T 16dea21c233d415799fc5422284f9acc P c6f0c249801d47c7807a85ec9b6ff8e3: Deleting log segment in path: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551012943-18375-0/minicluster-data/ts-0-root/wals/16dea21c233d415799fc5422284f9acc/wal-000000021 (ops 100-104)
I20260812 06:19:14.404121 18492 log.cc:1079] T 16dea21c233d415799fc5422284f9acc P c6f0c249801d47c7807a85ec9b6ff8e3: Deleting log segment in path: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551012943-18375-0/minicluster-data/ts-0-root/wals/16dea21c233d415799fc5422284f9acc/wal-000000022 (ops 105-109)
I20260812 06:19:14.404161 18492 log.cc:1079] T 16dea21c233d415799fc5422284f9acc P c6f0c249801d47c7807a85ec9b6ff8e3: Deleting log segment in path: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551012943-18375-0/minicluster-data/ts-0-root/wals/16dea21c233d415799fc5422284f9acc/wal-000000023 (ops 110-114)
I20260812 06:19:14.404201 18492 log.cc:1079] T 16dea21c233d415799fc5422284f9acc P c6f0c249801d47c7807a85ec9b6ff8e3: Deleting log segment in path: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551012943-18375-0/minicluster-data/ts-0-root/wals/16dea21c233d415799fc5422284f9acc/wal-000000024 (ops 115-119)
I20260812 06:19:14.404239 18492 log.cc:1079] T 16dea21c233d415799fc5422284f9acc P c6f0c249801d47c7807a85ec9b6ff8e3: Deleting log segment in path: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551012943-18375-0/minicluster-data/ts-0-root/wals/16dea21c233d415799fc5422284f9acc/wal-000000025 (ops 120-124)
I20260812 06:19:14.404279 18492 log.cc:1079] T 16dea21c233d415799fc5422284f9acc P c6f0c249801d47c7807a85ec9b6ff8e3: Deleting log segment in path: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551012943-18375-0/minicluster-data/ts-0-root/wals/16dea21c233d415799fc5422284f9acc/wal-000000026 (ops 125-129)
I20260812 06:19:14.436221 18492 maintenance_manager.cc:643] P c6f0c249801d47c7807a85ec9b6ff8e3: LogGCOp(16dea21c233d415799fc5422284f9acc) complete. Timing: real 0.033s	user 0.000s	sys 0.032s Metrics: {}
I20260812 06:19:14.436678 18565 maintenance_manager.cc:419] P c6f0c249801d47c7807a85ec9b6ff8e3: Scheduling FlushDeltaMemStoresOp(16dea21c233d415799fc5422284f9acc): perf score=5.165500
I20260812 06:19:14.453190 18492 maintenance_manager.cc:643] P c6f0c249801d47c7807a85ec9b6ff8e3: FlushDeltaMemStoresOp(16dea21c233d415799fc5422284f9acc) complete. Timing: real 0.016s	user 0.006s	sys 0.009s Metrics: {"bytes_written":6769230,"delete_count":0,"lbm_write_time_us":7070,"lbm_writes_lt_1ms":168,"reinsert_count":0,"update_count":825}
I20260812 06:19:14.453666 18565 maintenance_manager.cc:419] P c6f0c249801d47c7807a85ec9b6ff8e3: Scheduling FlushDeltaMemStoresOp(16dea21c233d415799fc5422284f9acc): perf score=1.000000
I20260812 06:19:14.468542 18492 maintenance_manager.cc:643] P c6f0c249801d47c7807a85ec9b6ff8e3: FlushDeltaMemStoresOp(16dea21c233d415799fc5422284f9acc) complete. Timing: real 0.015s	user 0.007s	sys 0.000s Metrics: {"bytes_written":1436027,"delete_count":0,"lbm_write_time_us":2737,"lbm_writes_lt_1ms":38,"reinsert_count":0,"update_count":175}
I20260812 06:19:14.469053 18565 maintenance_manager.cc:419] P c6f0c249801d47c7807a85ec9b6ff8e3: Scheduling UndoDeltaBlockGCOp(16dea21c233d415799fc5422284f9acc): 473 bytes on disk
I20260812 06:19:14.469609 18492 maintenance_manager.cc:643] P c6f0c249801d47c7807a85ec9b6ff8e3: UndoDeltaBlockGCOp(16dea21c233d415799fc5422284f9acc) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4}
I20260812 06:19:14.470134 18565 maintenance_manager.cc:419] P c6f0c249801d47c7807a85ec9b6ff8e3: Scheduling MajorDeltaCompactionOp(16dea21c233d415799fc5422284f9acc): perf score=1.000000
I20260812 06:19:14.641582 18492 maintenance_manager.cc:643] P c6f0c249801d47c7807a85ec9b6ff8e3: MajorDeltaCompactionOp(16dea21c233d415799fc5422284f9acc) complete. Timing: real 0.171s	user 0.115s	sys 0.055s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877272,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1686,"lbm_read_time_us":12160,"lbm_reads_lt_1ms":666,"lbm_write_time_us":34195,"lbm_writes_lt_1ms":643,"mutex_wait_us":1369,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":6656,"thread_start_us":76,"threads_started":1,"update_count":3000}
I20260812 06:19:14.642318 18565 maintenance_manager.cc:419] P c6f0c249801d47c7807a85ec9b6ff8e3: Scheduling FlushDeltaMemStoresOp(16dea21c233d415799fc5422284f9acc): perf score=15.087375
I20260812 06:19:14.690681 18492 maintenance_manager.cc:643] P c6f0c249801d47c7807a85ec9b6ff8e3: FlushDeltaMemStoresOp(16dea21c233d415799fc5422284f9acc) complete. Timing: real 0.048s	user 0.039s	sys 0.007s Metrics: {"bytes_written":16820142,"delete_count":0,"lbm_write_time_us":21268,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:19:14.691458 18565 maintenance_manager.cc:419] P c6f0c249801d47c7807a85ec9b6ff8e3: Scheduling FlushDeltaMemStoresOp(16dea21c233d415799fc5422284f9acc): perf score=2.188937
I20260812 06:19:14.703477 18492 maintenance_manager.cc:643] P c6f0c249801d47c7807a85ec9b6ff8e3: FlushDeltaMemStoresOp(16dea21c233d415799fc5422284f9acc) complete. Timing: real 0.012s	user 0.003s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4076,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:14.704046 18565 maintenance_manager.cc:419] P c6f0c249801d47c7807a85ec9b6ff8e3: Scheduling MajorDeltaCompactionOp(16dea21c233d415799fc5422284f9acc): perf score=1.000000
I20260812 06:19:14.858144 18492 maintenance_manager.cc:643] P c6f0c249801d47c7807a85ec9b6ff8e3: MajorDeltaCompactionOp(16dea21c233d415799fc5422284f9acc) complete. Timing: real 0.154s	user 0.106s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774675,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":219,"lbm_read_time_us":11558,"lbm_reads_lt_1ms":564,"lbm_write_time_us":29177,"lbm_writes_lt_1ms":543,"mutex_wait_us":23,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":20864,"update_count":2500}
I20260812 06:19:14.858858 18565 maintenance_manager.cc:419] P c6f0c249801d47c7807a85ec9b6ff8e3: Scheduling FlushDeltaMemStoresOp(16dea21c233d415799fc5422284f9acc): perf score=14.095187
I20260812 06:19:14.921917 18492 maintenance_manager.cc:643] P c6f0c249801d47c7807a85ec9b6ff8e3: FlushDeltaMemStoresOp(16dea21c233d415799fc5422284f9acc) complete. Timing: real 0.063s	user 0.030s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22271,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:14.922457 18565 maintenance_manager.cc:419] P c6f0c249801d47c7807a85ec9b6ff8e3: Scheduling FlushDeltaMemStoresOp(16dea21c233d415799fc5422284f9acc): perf score=2.188937
I20260812 06:19:14.934188 18492 maintenance_manager.cc:643] P c6f0c249801d47c7807a85ec9b6ff8e3: FlushDeltaMemStoresOp(16dea21c233d415799fc5422284f9acc) complete. Timing: real 0.012s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4340,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:14.934667 18565 maintenance_manager.cc:419] P c6f0c249801d47c7807a85ec9b6ff8e3: Scheduling MajorDeltaCompactionOp(16dea21c233d415799fc5422284f9acc): perf score=1.000000
I20260812 06:19:15.098129 18492 maintenance_manager.cc:643] P c6f0c249801d47c7807a85ec9b6ff8e3: MajorDeltaCompactionOp(16dea21c233d415799fc5422284f9acc) complete. Timing: real 0.163s	user 0.106s	sys 0.049s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":271,"lbm_read_time_us":11514,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28506,"lbm_writes_lt_1ms":543,"mutex_wait_us":25,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11904,"update_count":2500}
I20260812 06:19:15.098668 18565 maintenance_manager.cc:419] P c6f0c249801d47c7807a85ec9b6ff8e3: Scheduling FlushDeltaMemStoresOp(16dea21c233d415799fc5422284f9acc): perf score=14.095187
I20260812 06:19:15.161170 18492 maintenance_manager.cc:643] P c6f0c249801d47c7807a85ec9b6ff8e3: FlushDeltaMemStoresOp(16dea21c233d415799fc5422284f9acc) complete. Timing: real 0.062s	user 0.040s	sys 0.008s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21688,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:15.161710 18565 maintenance_manager.cc:419] P c6f0c249801d47c7807a85ec9b6ff8e3: Scheduling FlushDeltaMemStoresOp(16dea21c233d415799fc5422284f9acc): perf score=2.188937
I20260812 06:19:15.179207 18492 maintenance_manager.cc:643] P c6f0c249801d47c7807a85ec9b6ff8e3: FlushDeltaMemStoresOp(16dea21c233d415799fc5422284f9acc) complete. Timing: real 0.017s	user 0.010s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6628,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:15.179709 18565 maintenance_manager.cc:419] P c6f0c249801d47c7807a85ec9b6ff8e3: Scheduling MajorDeltaCompactionOp(16dea21c233d415799fc5422284f9acc): perf score=1.000000
I20260812 06:19:15.360816 18492 maintenance_manager.cc:643] P c6f0c249801d47c7807a85ec9b6ff8e3: MajorDeltaCompactionOp(16dea21c233d415799fc5422284f9acc) complete. Timing: real 0.180s	user 0.110s	sys 0.067s 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":286,"lbm_read_time_us":13138,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31257,"lbm_writes_lt_1ms":543,"mutex_wait_us":55,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:19:15.361528 18565 maintenance_manager.cc:419] P c6f0c249801d47c7807a85ec9b6ff8e3: Scheduling FlushDeltaMemStoresOp(16dea21c233d415799fc5422284f9acc): perf score=14.095187
I20260812 06:19:15.423079 18492 maintenance_manager.cc:643] P c6f0c249801d47c7807a85ec9b6ff8e3: FlushDeltaMemStoresOp(16dea21c233d415799fc5422284f9acc) complete. Timing: real 0.061s	user 0.041s	sys 0.016s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":22627,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:15.423645 18565 maintenance_manager.cc:419] P c6f0c249801d47c7807a85ec9b6ff8e3: Scheduling FlushDeltaMemStoresOp(16dea21c233d415799fc5422284f9acc): perf score=2.188937
I20260812 06:19:15.434779 18492 maintenance_manager.cc:643] P c6f0c249801d47c7807a85ec9b6ff8e3: FlushDeltaMemStoresOp(16dea21c233d415799fc5422284f9acc) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4379,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:15.435317 18565 maintenance_manager.cc:419] P c6f0c249801d47c7807a85ec9b6ff8e3: Scheduling MajorDeltaCompactionOp(16dea21c233d415799fc5422284f9acc): perf score=1.000000
I20260812 06:19:15.630649 18492 maintenance_manager.cc:643] P c6f0c249801d47c7807a85ec9b6ff8e3: MajorDeltaCompactionOp(16dea21c233d415799fc5422284f9acc) complete. Timing: real 0.195s	user 0.110s	sys 0.071s 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":460,"lbm_read_time_us":13900,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30781,"lbm_writes_lt_1ms":543,"mutex_wait_us":91,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5248,"update_count":2500}
I20260812 06:19:15.631342 18565 maintenance_manager.cc:419] P c6f0c249801d47c7807a85ec9b6ff8e3: Scheduling FlushDeltaMemStoresOp(16dea21c233d415799fc5422284f9acc): perf score=14.095187
I20260812 06:19:15.702939 18492 maintenance_manager.cc:643] P c6f0c249801d47c7807a85ec9b6ff8e3: FlushDeltaMemStoresOp(16dea21c233d415799fc5422284f9acc) complete. Timing: real 0.071s	user 0.046s	sys 0.020s Metrics: {"bytes_written":16409899,"delete_count":0,"lbm_write_time_us":26459,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:15.703506 18565 maintenance_manager.cc:419] P c6f0c249801d47c7807a85ec9b6ff8e3: Scheduling FlushDeltaMemStoresOp(16dea21c233d415799fc5422284f9acc): perf score=2.188937
I20260812 06:19:15.714126 18492 maintenance_manager.cc:643] P c6f0c249801d47c7807a85ec9b6ff8e3: FlushDeltaMemStoresOp(16dea21c233d415799fc5422284f9acc) complete. Timing: real 0.010s	user 0.004s	sys 0.004s 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:19:15.714614 18565 maintenance_manager.cc:419] P c6f0c249801d47c7807a85ec9b6ff8e3: Scheduling MajorDeltaCompactionOp(16dea21c233d415799fc5422284f9acc): perf score=1.000000
I20260812 06:19:15.890560 18492 maintenance_manager.cc:643] P c6f0c249801d47c7807a85ec9b6ff8e3: MajorDeltaCompactionOp(16dea21c233d415799fc5422284f9acc) complete. Timing: real 0.176s	user 0.128s	sys 0.047s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774686,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":672,"lbm_read_time_us":13957,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29933,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2432,"update_count":2500}
I20260812 06:19:15.891301 18565 maintenance_manager.cc:419] P c6f0c249801d47c7807a85ec9b6ff8e3: Scheduling FlushDeltaMemStoresOp(16dea21c233d415799fc5422284f9acc): perf score=10.126437
I20260812 06:19:15.931094 18492 maintenance_manager.cc:643] P c6f0c249801d47c7807a85ec9b6ff8e3: FlushDeltaMemStoresOp(16dea21c233d415799fc5422284f9acc) complete. Timing: real 0.040s	user 0.028s	sys 0.009s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17481,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:15.931717 18565 maintenance_manager.cc:419] P c6f0c249801d47c7807a85ec9b6ff8e3: Scheduling FlushDeltaMemStoresOp(16dea21c233d415799fc5422284f9acc): perf score=2.188937
I20260812 06:19:15.946549 18492 maintenance_manager.cc:643] P c6f0c249801d47c7807a85ec9b6ff8e3: FlushDeltaMemStoresOp(16dea21c233d415799fc5422284f9acc) complete. Timing: real 0.015s	user 0.008s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5877,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:15.947036 18565 maintenance_manager.cc:419] P c6f0c249801d47c7807a85ec9b6ff8e3: Scheduling FlushMRSOp(16dea21c233d415799fc5422284f9acc): perf score=1.000000
I20260812 06:19:15.978330 18492 maintenance_manager.cc:643] P c6f0c249801d47c7807a85ec9b6ff8e3: FlushMRSOp(16dea21c233d415799fc5422284f9acc) complete. Timing: real 0.031s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":92,"dirs.run_cpu_time_us":260,"dirs.run_wall_time_us":1512,"drs_written":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1467,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:15.979044 18565 maintenance_manager.cc:419] P c6f0c249801d47c7807a85ec9b6ff8e3: Scheduling LogGCOp(16dea21c233d415799fc5422284f9acc): free 121006704 bytes of WAL
I20260812 06:19:15.979327 18492 log_reader.cc:385] T 16dea21c233d415799fc5422284f9acc: removed 12 log segments from log reader
I20260812 06:19:15.979374 18492 log.cc:1079] T 16dea21c233d415799fc5422284f9acc P c6f0c249801d47c7807a85ec9b6ff8e3: Deleting log segment in path: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551012943-18375-0/minicluster-data/ts-0-root/wals/16dea21c233d415799fc5422284f9acc/wal-000000027 (ops 130-134)
I20260812 06:19:15.979405 18492 log.cc:1079] T 16dea21c233d415799fc5422284f9acc P c6f0c249801d47c7807a85ec9b6ff8e3: Deleting log segment in path: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551012943-18375-0/minicluster-data/ts-0-root/wals/16dea21c233d415799fc5422284f9acc/wal-000000028 (ops 135-139)
I20260812 06:19:15.979426 18492 log.cc:1079] T 16dea21c233d415799fc5422284f9acc P c6f0c249801d47c7807a85ec9b6ff8e3: Deleting log segment in path: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551012943-18375-0/minicluster-data/ts-0-root/wals/16dea21c233d415799fc5422284f9acc/wal-000000029 (ops 140-144)
I20260812 06:19:15.979496 18492 log.cc:1079] T 16dea21c233d415799fc5422284f9acc P c6f0c249801d47c7807a85ec9b6ff8e3: Deleting log segment in path: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551012943-18375-0/minicluster-data/ts-0-root/wals/16dea21c233d415799fc5422284f9acc/wal-000000030 (ops 145-149)
I20260812 06:19:15.979525 18492 log.cc:1079] T 16dea21c233d415799fc5422284f9acc P c6f0c249801d47c7807a85ec9b6ff8e3: Deleting log segment in path: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551012943-18375-0/minicluster-data/ts-0-root/wals/16dea21c233d415799fc5422284f9acc/wal-000000031 (ops 150-154)
I20260812 06:19:15.979611 18492 log.cc:1079] T 16dea21c233d415799fc5422284f9acc P c6f0c249801d47c7807a85ec9b6ff8e3: Deleting log segment in path: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551012943-18375-0/minicluster-data/ts-0-root/wals/16dea21c233d415799fc5422284f9acc/wal-000000032 (ops 155-159)
I20260812 06:19:15.979655 18492 log.cc:1079] T 16dea21c233d415799fc5422284f9acc P c6f0c249801d47c7807a85ec9b6ff8e3: Deleting log segment in path: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551012943-18375-0/minicluster-data/ts-0-root/wals/16dea21c233d415799fc5422284f9acc/wal-000000033 (ops 160-164)
I20260812 06:19:15.979688 18492 log.cc:1079] T 16dea21c233d415799fc5422284f9acc P c6f0c249801d47c7807a85ec9b6ff8e3: Deleting log segment in path: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551012943-18375-0/minicluster-data/ts-0-root/wals/16dea21c233d415799fc5422284f9acc/wal-000000034 (ops 165-168)
I20260812 06:19:15.979750 18492 log.cc:1079] T 16dea21c233d415799fc5422284f9acc P c6f0c249801d47c7807a85ec9b6ff8e3: Deleting log segment in path: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551012943-18375-0/minicluster-data/ts-0-root/wals/16dea21c233d415799fc5422284f9acc/wal-000000035 (ops 169-173)
I20260812 06:19:15.979802 18492 log.cc:1079] T 16dea21c233d415799fc5422284f9acc P c6f0c249801d47c7807a85ec9b6ff8e3: Deleting log segment in path: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551012943-18375-0/minicluster-data/ts-0-root/wals/16dea21c233d415799fc5422284f9acc/wal-000000036 (ops 174-178)
I20260812 06:19:15.979874 18492 log.cc:1079] T 16dea21c233d415799fc5422284f9acc P c6f0c249801d47c7807a85ec9b6ff8e3: Deleting log segment in path: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551012943-18375-0/minicluster-data/ts-0-root/wals/16dea21c233d415799fc5422284f9acc/wal-000000037 (ops 179-183)
I20260812 06:19:15.979959 18492 log.cc:1079] T 16dea21c233d415799fc5422284f9acc P c6f0c249801d47c7807a85ec9b6ff8e3: Deleting log segment in path: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551012943-18375-0/minicluster-data/ts-0-root/wals/16dea21c233d415799fc5422284f9acc/wal-000000038 (ops 184-188)
I20260812 06:19:16.012379 18492 maintenance_manager.cc:643] P c6f0c249801d47c7807a85ec9b6ff8e3: LogGCOp(16dea21c233d415799fc5422284f9acc) complete. Timing: real 0.033s	user 0.000s	sys 0.032s Metrics: {}
I20260812 06:19:16.012812 18565 maintenance_manager.cc:419] P c6f0c249801d47c7807a85ec9b6ff8e3: Scheduling FlushDeltaMemStoresOp(16dea21c233d415799fc5422284f9acc): perf score=5.165500
I20260812 06:19:16.036439 18492 maintenance_manager.cc:643] P c6f0c249801d47c7807a85ec9b6ff8e3: FlushDeltaMemStoresOp(16dea21c233d415799fc5422284f9acc) complete. Timing: real 0.023s	user 0.018s	sys 0.004s Metrics: {"bytes_written":7015375,"delete_count":0,"lbm_write_time_us":9876,"lbm_writes_lt_1ms":174,"reinsert_count":0,"update_count":855}
I20260812 06:19:16.036989 18565 maintenance_manager.cc:419] P c6f0c249801d47c7807a85ec9b6ff8e3: Scheduling LogGCOp(16dea21c233d415799fc5422284f9acc): free 11564893 bytes of WAL
I20260812 06:19:16.037285 18492 log_reader.cc:385] T 16dea21c233d415799fc5422284f9acc: removed 1 log segments from log reader
I20260812 06:19:16.037365 18492 log.cc:1079] T 16dea21c233d415799fc5422284f9acc P c6f0c249801d47c7807a85ec9b6ff8e3: Deleting log segment in path: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515551012943-18375-0/minicluster-data/ts-0-root/wals/16dea21c233d415799fc5422284f9acc/wal-000000039 (ops 189-192)
I20260812 06:19:16.040865 18492 maintenance_manager.cc:643] P c6f0c249801d47c7807a85ec9b6ff8e3: LogGCOp(16dea21c233d415799fc5422284f9acc) complete. Timing: real 0.004s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:19:16.041292 18565 maintenance_manager.cc:419] P c6f0c249801d47c7807a85ec9b6ff8e3: Scheduling UndoDeltaBlockGCOp(16dea21c233d415799fc5422284f9acc): 482 bytes on disk
I20260812 06:19:16.041893 18492 maintenance_manager.cc:643] P c6f0c249801d47c7807a85ec9b6ff8e3: UndoDeltaBlockGCOp(16dea21c233d415799fc5422284f9acc) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":85,"lbm_reads_lt_1ms":4}
I20260812 06:19:16.042459 18565 maintenance_manager.cc:419] P c6f0c249801d47c7807a85ec9b6ff8e3: Scheduling FlushDeltaMemStoresOp(16dea21c233d415799fc5422284f9acc): perf score=1.000000
I20260812 06:19:16.048923 18492 maintenance_manager.cc:643] P c6f0c249801d47c7807a85ec9b6ff8e3: FlushDeltaMemStoresOp(16dea21c233d415799fc5422284f9acc) complete. Timing: real 0.006s	user 0.005s	sys 0.000s Metrics: {"bytes_written":1189877,"delete_count":0,"lbm_write_time_us":1702,"lbm_writes_lt_1ms":32,"reinsert_count":0,"update_count":145}
I20260812 06:19:16.049443 18565 maintenance_manager.cc:419] P c6f0c249801d47c7807a85ec9b6ff8e3: Scheduling MajorDeltaCompactionOp(16dea21c233d415799fc5422284f9acc): perf score=1.000000
I20260812 06:19:16.230818 18375 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.929s	user 1.749s	sys 0.222s
I20260812 06:19:16.238493 18492 maintenance_manager.cc:643] P c6f0c249801d47c7807a85ec9b6ff8e3: MajorDeltaCompactionOp(16dea21c233d415799fc5422284f9acc) complete. Timing: real 0.189s	user 0.139s	sys 0.047s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877268,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"lbm_read_time_us":14588,"lbm_reads_lt_1ms":674,"lbm_write_time_us":33256,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":3000}
I20260812 06:19:16.239034 18565 maintenance_manager.cc:419] P c6f0c249801d47c7807a85ec9b6ff8e3: Scheduling FlushDeltaMemStoresOp(16dea21c233d415799fc5422284f9acc): perf score=14.095187
I20260812 06:19:16.293160 18492 maintenance_manager.cc:643] P c6f0c249801d47c7807a85ec9b6ff8e3: FlushDeltaMemStoresOp(16dea21c233d415799fc5422284f9acc) complete. Timing: real 0.054s	user 0.041s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24915,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":4224,"update_count":2000}
I20260812 06:19:16.293836 18565 maintenance_manager.cc:419] P c6f0c249801d47c7807a85ec9b6ff8e3: Scheduling MajorDeltaCompactionOp(16dea21c233d415799fc5422284f9acc): perf score=1.000000
I20260812 06:19:16.349514 18375 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.118s	user 0.003s	sys 0.000s
I20260812 06:19:16.350391 18375 tablet_server.cc:179] TabletServer@127.17.241.193:0 shutting down...
I20260812 06:19:16.436115 18492 maintenance_manager.cc:643] P c6f0c249801d47c7807a85ec9b6ff8e3: MajorDeltaCompactionOp(16dea21c233d415799fc5422284f9acc) complete. Timing: real 0.142s	user 0.082s	sys 0.056s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672157,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":1009,"lbm_read_time_us":9011,"lbm_reads_lt_1ms":467,"lbm_write_time_us":24401,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4992,"update_count":2000}
I20260812 06:19:16.436839 18375 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:16.437506 18375 tablet_replica.cc:333] T 16dea21c233d415799fc5422284f9acc P c6f0c249801d47c7807a85ec9b6ff8e3: stopping tablet replica
I20260812 06:19:16.437824 18375 raft_consensus.cc:2243] T 16dea21c233d415799fc5422284f9acc P c6f0c249801d47c7807a85ec9b6ff8e3 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:16.438074 18375 raft_consensus.cc:2272] T 16dea21c233d415799fc5422284f9acc P c6f0c249801d47c7807a85ec9b6ff8e3 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:16.454349 18375 tablet_server.cc:196] TabletServer@127.17.241.193:0 shutdown complete.
I20260812 06:19:16.475957 18375 master.cc:562] Master@127.17.241.254:38885 shutting down...
I20260812 06:19:16.480476 18375 raft_consensus.cc:2243] T 00000000000000000000000000000000 P c1bee2872ab34f8bb45443a5df4d4d5b [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:16.480715 18375 raft_consensus.cc:2272] T 00000000000000000000000000000000 P c1bee2872ab34f8bb45443a5df4d4d5b [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:16.480821 18375 tablet_replica.cc:333] T 00000000000000000000000000000000 P c1bee2872ab34f8bb45443a5df4d4d5b: stopping tablet replica
I20260812 06:19:16.493870 18375 master.cc:584] Master@127.17.241.254:38885 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5565 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:19:16.588644 18375 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.17.241.254:46165
I20260812 06:19:16.589067 18375 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:16.591612 18603 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:16.591619 18606 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:16.591603 18604 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:16.591799 18375 server_base.cc:1061] running on GCE node
I20260812 06:19:16.592155 18375 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:16.592197 18375 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:16.592212 18375 hybrid_clock.cc:648] HybridClock initialized: now 1786515556592212 us; error 0 us; skew 500 ppm
I20260812 06:19:16.593057 18375 webserver.cc:533] Webserver started at http://127.17.241.254:33907/ using document root <none> and password file <none>
I20260812 06:19:16.593248 18375 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:16.593325 18375 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:16.593405 18375 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:16.593808 18375 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551012943-18375-0/minicluster-data/master-0-root/instance:
uuid: "b38ce6d616604dacbb8a7c650472ab75"
format_stamp: "Formatted at 2026-08-12 06:19:16 on dist-test-slave-1xrh"
I20260812 06:19:16.595402 18375 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:16.596349 18611 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:16.596619 18375 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:16.596719 18375 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551012943-18375-0/minicluster-data/master-0-root
uuid: "b38ce6d616604dacbb8a7c650472ab75"
format_stamp: "Formatted at 2026-08-12 06:19:16 on dist-test-slave-1xrh"
I20260812 06:19:16.596808 18375 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551012943-18375-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551012943-18375-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551012943-18375-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:16.613585 18375 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:16.613961 18375 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:16.618300 18375 rpc_server.cc:307] RPC server started. Bound to: 127.17.241.254:46165
I20260812 06:19:16.640089 18673 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.17.241.254:46165 every 8 connection(s)
I20260812 06:19:16.640705 18674 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:16.642565 18674 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P b38ce6d616604dacbb8a7c650472ab75: Bootstrap starting.
I20260812 06:19:16.643407 18674 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P b38ce6d616604dacbb8a7c650472ab75: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:16.644505 18674 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P b38ce6d616604dacbb8a7c650472ab75: No bootstrap required, opened a new log
I20260812 06:19:16.644942 18674 raft_consensus.cc:359] T 00000000000000000000000000000000 P b38ce6d616604dacbb8a7c650472ab75 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b38ce6d616604dacbb8a7c650472ab75" member_type: VOTER }
I20260812 06:19:16.645030 18674 raft_consensus.cc:385] T 00000000000000000000000000000000 P b38ce6d616604dacbb8a7c650472ab75 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:16.645083 18674 raft_consensus.cc:740] T 00000000000000000000000000000000 P b38ce6d616604dacbb8a7c650472ab75 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: b38ce6d616604dacbb8a7c650472ab75, State: Initialized, Role: FOLLOWER
I20260812 06:19:16.645282 18674 consensus_queue.cc:260] T 00000000000000000000000000000000 P b38ce6d616604dacbb8a7c650472ab75 [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: "b38ce6d616604dacbb8a7c650472ab75" member_type: VOTER }
I20260812 06:19:16.645358 18674 raft_consensus.cc:399] T 00000000000000000000000000000000 P b38ce6d616604dacbb8a7c650472ab75 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:16.645434 18674 raft_consensus.cc:493] T 00000000000000000000000000000000 P b38ce6d616604dacbb8a7c650472ab75 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:16.645495 18674 raft_consensus.cc:3060] T 00000000000000000000000000000000 P b38ce6d616604dacbb8a7c650472ab75 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:16.646202 18674 raft_consensus.cc:515] T 00000000000000000000000000000000 P b38ce6d616604dacbb8a7c650472ab75 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b38ce6d616604dacbb8a7c650472ab75" member_type: VOTER }
I20260812 06:19:16.646360 18674 leader_election.cc:304] T 00000000000000000000000000000000 P b38ce6d616604dacbb8a7c650472ab75 [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: b38ce6d616604dacbb8a7c650472ab75; no voters: 
I20260812 06:19:16.646589 18674 leader_election.cc:290] T 00000000000000000000000000000000 P b38ce6d616604dacbb8a7c650472ab75 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:16.646730 18678 raft_consensus.cc:2804] T 00000000000000000000000000000000 P b38ce6d616604dacbb8a7c650472ab75 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:16.646991 18678 raft_consensus.cc:697] T 00000000000000000000000000000000 P b38ce6d616604dacbb8a7c650472ab75 [term 1 LEADER]: Becoming Leader. State: Replica: b38ce6d616604dacbb8a7c650472ab75, State: Running, Role: LEADER
I20260812 06:19:16.647106 18674 sys_catalog.cc:565] T 00000000000000000000000000000000 P b38ce6d616604dacbb8a7c650472ab75 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:16.647149 18678 consensus_queue.cc:237] T 00000000000000000000000000000000 P b38ce6d616604dacbb8a7c650472ab75 [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: "b38ce6d616604dacbb8a7c650472ab75" member_type: VOTER }
I20260812 06:19:16.647629 18680 sys_catalog.cc:455] T 00000000000000000000000000000000 P b38ce6d616604dacbb8a7c650472ab75 [sys.catalog]: SysCatalogTable state changed. Reason: New leader b38ce6d616604dacbb8a7c650472ab75. Latest consensus state: current_term: 1 leader_uuid: "b38ce6d616604dacbb8a7c650472ab75" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b38ce6d616604dacbb8a7c650472ab75" member_type: VOTER } }
I20260812 06:19:16.647614 18679 sys_catalog.cc:455] T 00000000000000000000000000000000 P b38ce6d616604dacbb8a7c650472ab75 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "b38ce6d616604dacbb8a7c650472ab75" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "b38ce6d616604dacbb8a7c650472ab75" member_type: VOTER } }
I20260812 06:19:16.647751 18680 sys_catalog.cc:458] T 00000000000000000000000000000000 P b38ce6d616604dacbb8a7c650472ab75 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:16.647818 18679 sys_catalog.cc:458] T 00000000000000000000000000000000 P b38ce6d616604dacbb8a7c650472ab75 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:16.648447 18684 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:16.649148 18684 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:16.649446 18375 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:16.650962 18684 catalog_manager.cc:1383] Generated new cluster ID: 1fd3693810d04d97b76ffadd80cc1440
I20260812 06:19:16.651013 18684 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:16.664081 18684 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:16.664767 18684 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:16.668910 18684 catalog_manager.cc:6092] T 00000000000000000000000000000000 P b38ce6d616604dacbb8a7c650472ab75: Generated new TSK 0
I20260812 06:19:16.669080 18684 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:16.681648 18375 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:16.683635 18700 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:16.683657 18698 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:16.683658 18703 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:16.683734 18375 server_base.cc:1061] running on GCE node
I20260812 06:19:16.684010 18375 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:16.684054 18375 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:16.684070 18375 hybrid_clock.cc:648] HybridClock initialized: now 1786515556684070 us; error 0 us; skew 500 ppm
I20260812 06:19:16.684815 18375 webserver.cc:533] Webserver started at http://127.17.241.193:43851/ using document root <none> and password file <none>
I20260812 06:19:16.684947 18375 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:16.684988 18375 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:16.685038 18375 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:16.685387 18375 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551012943-18375-0/minicluster-data/ts-0-root/instance:
uuid: "81887ede3a4e4593a16078c62520fa94"
format_stamp: "Formatted at 2026-08-12 06:19:16 on dist-test-slave-1xrh"
I20260812 06:19:16.686861 18375 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:16.687841 18708 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:16.688078 18375 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:19:16.688143 18375 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551012943-18375-0/minicluster-data/ts-0-root
uuid: "81887ede3a4e4593a16078c62520fa94"
format_stamp: "Formatted at 2026-08-12 06:19:16 on dist-test-slave-1xrh"
I20260812 06:19:16.688196 18375 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551012943-18375-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551012943-18375-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551012943-18375-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:16.709143 18375 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:16.709486 18375 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:16.709738 18375 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:16.710250 18375 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:16.710290 18375 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:16.710359 18375 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:16.710407 18375 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:16.714787 18375 rpc_server.cc:307] RPC server started. Bound to: 127.17.241.193:46609
I20260812 06:19:16.714825 18781 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.17.241.193:46609 every 8 connection(s)
I20260812 06:19:16.722932 18782 heartbeater.cc:344] Connected to a master server at 127.17.241.254:46165
I20260812 06:19:16.723031 18782 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:16.723388 18782 heartbeater.cc:507] Master 127.17.241.254:46165 requested a full tablet report, sending...
I20260812 06:19:16.724188 18631 ts_manager.cc:194] Registered new tserver with Master: 81887ede3a4e4593a16078c62520fa94 (127.17.241.193:46609)
I20260812 06:19:16.724858 18631 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:39432
I20260812 06:19:16.725232 18375 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.009948437s
I20260812 06:19:16.732074 18631 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:39434:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:19:16.740502 18744 tablet_service.cc:1511] Processing CreateTablet for tablet 2861e5e24e404c0683409629fbe0a123 (DEFAULT_TABLE table=heavy-update-compaction-test [id=0a180ee4587249edba7d6bbf661c77fe]), partition=
I20260812 06:19:16.740736 18744 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 2861e5e24e404c0683409629fbe0a123. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:16.742547 18795 tablet_bootstrap.cc:492] T 2861e5e24e404c0683409629fbe0a123 P 81887ede3a4e4593a16078c62520fa94: Bootstrap starting.
I20260812 06:19:16.743623 18795 tablet_bootstrap.cc:654] T 2861e5e24e404c0683409629fbe0a123 P 81887ede3a4e4593a16078c62520fa94: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:16.744724 18795 tablet_bootstrap.cc:492] T 2861e5e24e404c0683409629fbe0a123 P 81887ede3a4e4593a16078c62520fa94: No bootstrap required, opened a new log
I20260812 06:19:16.744798 18795 ts_tablet_manager.cc:1403] T 2861e5e24e404c0683409629fbe0a123 P 81887ede3a4e4593a16078c62520fa94: Time spent bootstrapping tablet: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:19:16.745231 18795 raft_consensus.cc:359] T 2861e5e24e404c0683409629fbe0a123 P 81887ede3a4e4593a16078c62520fa94 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "81887ede3a4e4593a16078c62520fa94" member_type: VOTER last_known_addr { host: "127.17.241.193" port: 46609 } }
I20260812 06:19:16.745316 18795 raft_consensus.cc:385] T 2861e5e24e404c0683409629fbe0a123 P 81887ede3a4e4593a16078c62520fa94 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:16.745394 18795 raft_consensus.cc:740] T 2861e5e24e404c0683409629fbe0a123 P 81887ede3a4e4593a16078c62520fa94 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 81887ede3a4e4593a16078c62520fa94, State: Initialized, Role: FOLLOWER
I20260812 06:19:16.745548 18795 consensus_queue.cc:260] T 2861e5e24e404c0683409629fbe0a123 P 81887ede3a4e4593a16078c62520fa94 [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: "81887ede3a4e4593a16078c62520fa94" member_type: VOTER last_known_addr { host: "127.17.241.193" port: 46609 } }
I20260812 06:19:16.745631 18795 raft_consensus.cc:399] T 2861e5e24e404c0683409629fbe0a123 P 81887ede3a4e4593a16078c62520fa94 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:16.745699 18795 raft_consensus.cc:493] T 2861e5e24e404c0683409629fbe0a123 P 81887ede3a4e4593a16078c62520fa94 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:16.745762 18795 raft_consensus.cc:3060] T 2861e5e24e404c0683409629fbe0a123 P 81887ede3a4e4593a16078c62520fa94 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:16.746665 18795 raft_consensus.cc:515] T 2861e5e24e404c0683409629fbe0a123 P 81887ede3a4e4593a16078c62520fa94 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "81887ede3a4e4593a16078c62520fa94" member_type: VOTER last_known_addr { host: "127.17.241.193" port: 46609 } }
I20260812 06:19:16.746784 18795 leader_election.cc:304] T 2861e5e24e404c0683409629fbe0a123 P 81887ede3a4e4593a16078c62520fa94 [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: 81887ede3a4e4593a16078c62520fa94; no voters: 
I20260812 06:19:16.746932 18795 leader_election.cc:290] T 2861e5e24e404c0683409629fbe0a123 P 81887ede3a4e4593a16078c62520fa94 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:16.747071 18797 raft_consensus.cc:2804] T 2861e5e24e404c0683409629fbe0a123 P 81887ede3a4e4593a16078c62520fa94 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:16.747285 18795 ts_tablet_manager.cc:1434] T 2861e5e24e404c0683409629fbe0a123 P 81887ede3a4e4593a16078c62520fa94: Time spent starting tablet: real 0.002s	user 0.000s	sys 0.003s
I20260812 06:19:16.747306 18782 heartbeater.cc:499] Master 127.17.241.254:46165 was elected leader, sending a full tablet report...
I20260812 06:19:16.747315 18797 raft_consensus.cc:697] T 2861e5e24e404c0683409629fbe0a123 P 81887ede3a4e4593a16078c62520fa94 [term 1 LEADER]: Becoming Leader. State: Replica: 81887ede3a4e4593a16078c62520fa94, State: Running, Role: LEADER
I20260812 06:19:16.747519 18797 consensus_queue.cc:237] T 2861e5e24e404c0683409629fbe0a123 P 81887ede3a4e4593a16078c62520fa94 [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: "81887ede3a4e4593a16078c62520fa94" member_type: VOTER last_known_addr { host: "127.17.241.193" port: 46609 } }
I20260812 06:19:16.748816 18631 catalog_manager.cc:5719] T 2861e5e24e404c0683409629fbe0a123 P 81887ede3a4e4593a16078c62520fa94 reported cstate change: term changed from 0 to 1, leader changed from <none> to 81887ede3a4e4593a16078c62520fa94 (127.17.241.193). New cstate: current_term: 1 leader_uuid: "81887ede3a4e4593a16078c62520fa94" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "81887ede3a4e4593a16078c62520fa94" member_type: VOTER last_known_addr { host: "127.17.241.193" port: 46609 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:16.810937 18375 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.054s	user 0.009s	sys 0.014s
I20260812 06:19:16.965981 18783 maintenance_manager.cc:419] P 81887ede3a4e4593a16078c62520fa94: Scheduling FlushMRSOp(2861e5e24e404c0683409629fbe0a123): perf score=19.054940
I20260812 06:19:17.138653 18713 maintenance_manager.cc:643] P 81887ede3a4e4593a16078c62520fa94: FlushMRSOp(2861e5e24e404c0683409629fbe0a123) complete. Timing: real 0.172s	user 0.128s	sys 0.039s Metrics: {"bytes_written":13086942,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":81,"dirs.run_cpu_time_us":231,"dirs.run_wall_time_us":910,"drs_written":1,"lbm_read_time_us":68,"lbm_reads_lt_1ms":4,"lbm_write_time_us":44817,"lbm_writes_lt_1ms":776,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":3968,"update_count":1595}
I20260812 06:19:17.139436 18783 maintenance_manager.cc:419] P 81887ede3a4e4593a16078c62520fa94: Scheduling LogGCOp(2861e5e24e404c0683409629fbe0a123): free 20743880 bytes of WAL
I20260812 06:19:17.139662 18713 log_reader.cc:385] T 2861e5e24e404c0683409629fbe0a123: removed 2 log segments from log reader
I20260812 06:19:17.139734 18713 log.cc:1079] T 2861e5e24e404c0683409629fbe0a123 P 81887ede3a4e4593a16078c62520fa94: Deleting log segment in path: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551012943-18375-0/minicluster-data/ts-0-root/wals/2861e5e24e404c0683409629fbe0a123/wal-000000001 (ops 1-6)
I20260812 06:19:17.139814 18713 log.cc:1079] T 2861e5e24e404c0683409629fbe0a123 P 81887ede3a4e4593a16078c62520fa94: Deleting log segment in path: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551012943-18375-0/minicluster-data/ts-0-root/wals/2861e5e24e404c0683409629fbe0a123/wal-000000002 (ops 7-11)
I20260812 06:19:17.145879 18713 maintenance_manager.cc:643] P 81887ede3a4e4593a16078c62520fa94: LogGCOp(2861e5e24e404c0683409629fbe0a123) complete. Timing: real 0.006s	user 0.004s	sys 0.000s Metrics: {}
I20260812 06:19:17.146193 18783 maintenance_manager.cc:419] P 81887ede3a4e4593a16078c62520fa94: Scheduling FlushDeltaMemStoresOp(2861e5e24e404c0683409629fbe0a123): perf score=2.188937
I20260812 06:19:17.163308 18713 maintenance_manager.cc:643] P 81887ede3a4e4593a16078c62520fa94: FlushDeltaMemStoresOp(2861e5e24e404c0683409629fbe0a123) complete. Timing: real 0.017s	user 0.011s	sys 0.004s Metrics: {"bytes_written":3733436,"delete_count":0,"lbm_write_time_us":5972,"lbm_writes_lt_1ms":94,"reinsert_count":0,"update_count":455}
I20260812 06:19:17.163731 18783 maintenance_manager.cc:419] P 81887ede3a4e4593a16078c62520fa94: Scheduling UndoDeltaBlockGCOp(2861e5e24e404c0683409629fbe0a123): 16411391 bytes on disk
I20260812 06:19:17.164208 18713 maintenance_manager.cc:643] P 81887ede3a4e4593a16078c62520fa94: UndoDeltaBlockGCOp(2861e5e24e404c0683409629fbe0a123) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":51,"lbm_reads_lt_1ms":4}
I20260812 06:19:17.164615 18783 maintenance_manager.cc:419] P 81887ede3a4e4593a16078c62520fa94: Scheduling FlushDeltaMemStoresOp(2861e5e24e404c0683409629fbe0a123): perf score=2.188937
I20260812 06:19:17.174547 18713 maintenance_manager.cc:643] P 81887ede3a4e4593a16078c62520fa94: FlushDeltaMemStoresOp(2861e5e24e404c0683409629fbe0a123) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4058,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:17.174928 18783 maintenance_manager.cc:419] P 81887ede3a4e4593a16078c62520fa94: Scheduling MajorDeltaCompactionOp(2861e5e24e404c0683409629fbe0a123): perf score=1.000000
I20260812 06:19:17.358850 18713 maintenance_manager.cc:643] P 81887ede3a4e4593a16078c62520fa94: MajorDeltaCompactionOp(2861e5e24e404c0683409629fbe0a123) complete. Timing: real 0.184s	user 0.134s	sys 0.045s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774783,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":832,"lbm_read_time_us":12158,"lbm_reads_lt_1ms":569,"lbm_write_time_us":33749,"lbm_writes_lt_1ms":543,"mutex_wait_us":20,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7680,"thread_start_us":380,"threads_started":5,"update_count":2500}
I20260812 06:19:17.359593 18783 maintenance_manager.cc:419] P 81887ede3a4e4593a16078c62520fa94: Scheduling FlushDeltaMemStoresOp(2861e5e24e404c0683409629fbe0a123): perf score=14.095187
I20260812 06:19:17.411787 18713 maintenance_manager.cc:643] P 81887ede3a4e4593a16078c62520fa94: FlushDeltaMemStoresOp(2861e5e24e404c0683409629fbe0a123) complete. Timing: real 0.052s	user 0.020s	sys 0.027s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":21389,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:17.412256 18783 maintenance_manager.cc:419] P 81887ede3a4e4593a16078c62520fa94: Scheduling FlushDeltaMemStoresOp(2861e5e24e404c0683409629fbe0a123): perf score=2.188937
I20260812 06:19:17.423557 18713 maintenance_manager.cc:643] P 81887ede3a4e4593a16078c62520fa94: FlushDeltaMemStoresOp(2861e5e24e404c0683409629fbe0a123) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4227,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:17.424032 18783 maintenance_manager.cc:419] P 81887ede3a4e4593a16078c62520fa94: Scheduling MajorDeltaCompactionOp(2861e5e24e404c0683409629fbe0a123): perf score=1.000000
I20260812 06:19:17.587008 18713 maintenance_manager.cc:643] P 81887ede3a4e4593a16078c62520fa94: MajorDeltaCompactionOp(2861e5e24e404c0683409629fbe0a123) complete. Timing: real 0.163s	user 0.123s	sys 0.037s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":199,"lbm_read_time_us":11898,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33328,"lbm_writes_lt_1ms":543,"mutex_wait_us":73,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:19:17.587767 18783 maintenance_manager.cc:419] P 81887ede3a4e4593a16078c62520fa94: Scheduling FlushDeltaMemStoresOp(2861e5e24e404c0683409629fbe0a123): perf score=14.095187
I20260812 06:19:17.634773 18713 maintenance_manager.cc:643] P 81887ede3a4e4593a16078c62520fa94: FlushDeltaMemStoresOp(2861e5e24e404c0683409629fbe0a123) complete. Timing: real 0.047s	user 0.023s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20535,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:17.635311 18783 maintenance_manager.cc:419] P 81887ede3a4e4593a16078c62520fa94: Scheduling FlushDeltaMemStoresOp(2861e5e24e404c0683409629fbe0a123): perf score=2.188937
I20260812 06:19:17.646618 18713 maintenance_manager.cc:643] P 81887ede3a4e4593a16078c62520fa94: FlushDeltaMemStoresOp(2861e5e24e404c0683409629fbe0a123) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4202,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:17.647082 18783 maintenance_manager.cc:419] P 81887ede3a4e4593a16078c62520fa94: Scheduling MajorDeltaCompactionOp(2861e5e24e404c0683409629fbe0a123): perf score=1.000000
I20260812 06:19:17.820756 18713 maintenance_manager.cc:643] P 81887ede3a4e4593a16078c62520fa94: MajorDeltaCompactionOp(2861e5e24e404c0683409629fbe0a123) complete. Timing: real 0.173s	user 0.107s	sys 0.057s 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":239,"lbm_read_time_us":10697,"lbm_reads_lt_1ms":572,"lbm_write_time_us":33380,"lbm_writes_lt_1ms":543,"mutex_wait_us":22,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9472,"update_count":2500}
I20260812 06:19:17.821480 18783 maintenance_manager.cc:419] P 81887ede3a4e4593a16078c62520fa94: Scheduling FlushDeltaMemStoresOp(2861e5e24e404c0683409629fbe0a123): perf score=14.095187
I20260812 06:19:17.874596 18713 maintenance_manager.cc:643] P 81887ede3a4e4593a16078c62520fa94: FlushDeltaMemStoresOp(2861e5e24e404c0683409629fbe0a123) complete. Timing: real 0.053s	user 0.023s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23258,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:17.875092 18783 maintenance_manager.cc:419] P 81887ede3a4e4593a16078c62520fa94: Scheduling MajorDeltaCompactionOp(2861e5e24e404c0683409629fbe0a123): perf score=1.000000
I20260812 06:19:18.033828 18713 maintenance_manager.cc:643] P 81887ede3a4e4593a16078c62520fa94: MajorDeltaCompactionOp(2861e5e24e404c0683409629fbe0a123) complete. Timing: real 0.159s	user 0.105s	sys 0.049s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672157,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":266,"lbm_read_time_us":10498,"lbm_reads_lt_1ms":463,"lbm_write_time_us":27042,"lbm_writes_lt_1ms":443,"mutex_wait_us":79,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:18.034507 18783 maintenance_manager.cc:419] P 81887ede3a4e4593a16078c62520fa94: Scheduling FlushDeltaMemStoresOp(2861e5e24e404c0683409629fbe0a123): perf score=14.095187
I20260812 06:19:18.087610 18713 maintenance_manager.cc:643] P 81887ede3a4e4593a16078c62520fa94: FlushDeltaMemStoresOp(2861e5e24e404c0683409629fbe0a123) complete. Timing: real 0.053s	user 0.042s	sys 0.011s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":23067,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:18.088136 18783 maintenance_manager.cc:419] P 81887ede3a4e4593a16078c62520fa94: Scheduling FlushDeltaMemStoresOp(2861e5e24e404c0683409629fbe0a123): perf score=2.188937
I20260812 06:19:18.100888 18713 maintenance_manager.cc:643] P 81887ede3a4e4593a16078c62520fa94: FlushDeltaMemStoresOp(2861e5e24e404c0683409629fbe0a123) complete. Timing: real 0.013s	user 0.006s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5174,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:18.101390 18783 maintenance_manager.cc:419] P 81887ede3a4e4593a16078c62520fa94: Scheduling MajorDeltaCompactionOp(2861e5e24e404c0683409629fbe0a123): perf score=1.000000
I20260812 06:19:18.281848 18713 maintenance_manager.cc:643] P 81887ede3a4e4593a16078c62520fa94: MajorDeltaCompactionOp(2861e5e24e404c0683409629fbe0a123) complete. Timing: real 0.180s	user 0.138s	sys 0.039s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":221,"lbm_read_time_us":10516,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29139,"lbm_writes_lt_1ms":543,"mutex_wait_us":21,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":19712,"update_count":2500}
I20260812 06:19:18.282501 18783 maintenance_manager.cc:419] P 81887ede3a4e4593a16078c62520fa94: Scheduling FlushDeltaMemStoresOp(2861e5e24e404c0683409629fbe0a123): perf score=14.095187
I20260812 06:19:18.337505 18713 maintenance_manager.cc:643] P 81887ede3a4e4593a16078c62520fa94: FlushDeltaMemStoresOp(2861e5e24e404c0683409629fbe0a123) complete. Timing: real 0.055s	user 0.034s	sys 0.017s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22560,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:18.338152 18783 maintenance_manager.cc:419] P 81887ede3a4e4593a16078c62520fa94: Scheduling FlushDeltaMemStoresOp(2861e5e24e404c0683409629fbe0a123): perf score=2.188937
I20260812 06:19:18.361680 18713 maintenance_manager.cc:643] P 81887ede3a4e4593a16078c62520fa94: FlushDeltaMemStoresOp(2861e5e24e404c0683409629fbe0a123) complete. Timing: real 0.023s	user 0.014s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6426,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:18.362250 18783 maintenance_manager.cc:419] P 81887ede3a4e4593a16078c62520fa94: Scheduling FlushDeltaMemStoresOp(2861e5e24e404c0683409629fbe0a123): perf score=2.188937
I20260812 06:19:18.385262 18713 maintenance_manager.cc:643] P 81887ede3a4e4593a16078c62520fa94: FlushDeltaMemStoresOp(2861e5e24e404c0683409629fbe0a123) complete. Timing: real 0.023s	user 0.008s	sys 0.012s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4028,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:18.386018 18783 maintenance_manager.cc:419] P 81887ede3a4e4593a16078c62520fa94: Scheduling FlushMRSOp(2861e5e24e404c0683409629fbe0a123): perf score=1.000000
I20260812 06:19:18.425307 18713 maintenance_manager.cc:643] P 81887ede3a4e4593a16078c62520fa94: FlushMRSOp(2861e5e24e404c0683409629fbe0a123) complete. Timing: real 0.039s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":71,"dirs.run_cpu_time_us":263,"dirs.run_wall_time_us":1641,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1667,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30,"spinlock_wait_cycles":1920}
I20260812 06:19:18.425906 18783 maintenance_manager.cc:419] P 81887ede3a4e4593a16078c62520fa94: Scheduling LogGCOp(2861e5e24e404c0683409629fbe0a123): free 120553386 bytes of WAL
I20260812 06:19:18.426206 18713 log_reader.cc:385] T 2861e5e24e404c0683409629fbe0a123: removed 12 log segments from log reader
I20260812 06:19:18.426254 18713 log.cc:1079] T 2861e5e24e404c0683409629fbe0a123 P 81887ede3a4e4593a16078c62520fa94: Deleting log segment in path: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551012943-18375-0/minicluster-data/ts-0-root/wals/2861e5e24e404c0683409629fbe0a123/wal-000000003 (ops 12-16)
I20260812 06:19:18.426285 18713 log.cc:1079] T 2861e5e24e404c0683409629fbe0a123 P 81887ede3a4e4593a16078c62520fa94: Deleting log segment in path: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551012943-18375-0/minicluster-data/ts-0-root/wals/2861e5e24e404c0683409629fbe0a123/wal-000000004 (ops 17-21)
I20260812 06:19:18.426344 18713 log.cc:1079] T 2861e5e24e404c0683409629fbe0a123 P 81887ede3a4e4593a16078c62520fa94: Deleting log segment in path: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551012943-18375-0/minicluster-data/ts-0-root/wals/2861e5e24e404c0683409629fbe0a123/wal-000000005 (ops 22-26)
I20260812 06:19:18.426380 18713 log.cc:1079] T 2861e5e24e404c0683409629fbe0a123 P 81887ede3a4e4593a16078c62520fa94: Deleting log segment in path: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551012943-18375-0/minicluster-data/ts-0-root/wals/2861e5e24e404c0683409629fbe0a123/wal-000000006 (ops 27-30)
I20260812 06:19:18.426417 18713 log.cc:1079] T 2861e5e24e404c0683409629fbe0a123 P 81887ede3a4e4593a16078c62520fa94: Deleting log segment in path: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551012943-18375-0/minicluster-data/ts-0-root/wals/2861e5e24e404c0683409629fbe0a123/wal-000000007 (ops 31-35)
I20260812 06:19:18.426455 18713 log.cc:1079] T 2861e5e24e404c0683409629fbe0a123 P 81887ede3a4e4593a16078c62520fa94: Deleting log segment in path: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551012943-18375-0/minicluster-data/ts-0-root/wals/2861e5e24e404c0683409629fbe0a123/wal-000000008 (ops 36-40)
I20260812 06:19:18.426493 18713 log.cc:1079] T 2861e5e24e404c0683409629fbe0a123 P 81887ede3a4e4593a16078c62520fa94: Deleting log segment in path: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551012943-18375-0/minicluster-data/ts-0-root/wals/2861e5e24e404c0683409629fbe0a123/wal-000000009 (ops 41-45)
I20260812 06:19:18.426530 18713 log.cc:1079] T 2861e5e24e404c0683409629fbe0a123 P 81887ede3a4e4593a16078c62520fa94: Deleting log segment in path: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551012943-18375-0/minicluster-data/ts-0-root/wals/2861e5e24e404c0683409629fbe0a123/wal-000000010 (ops 46-50)
I20260812 06:19:18.426616 18713 log.cc:1079] T 2861e5e24e404c0683409629fbe0a123 P 81887ede3a4e4593a16078c62520fa94: Deleting log segment in path: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551012943-18375-0/minicluster-data/ts-0-root/wals/2861e5e24e404c0683409629fbe0a123/wal-000000011 (ops 51-54)
I20260812 06:19:18.426683 18713 log.cc:1079] T 2861e5e24e404c0683409629fbe0a123 P 81887ede3a4e4593a16078c62520fa94: Deleting log segment in path: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551012943-18375-0/minicluster-data/ts-0-root/wals/2861e5e24e404c0683409629fbe0a123/wal-000000012 (ops 55-59)
I20260812 06:19:18.426708 18713 log.cc:1079] T 2861e5e24e404c0683409629fbe0a123 P 81887ede3a4e4593a16078c62520fa94: Deleting log segment in path: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551012943-18375-0/minicluster-data/ts-0-root/wals/2861e5e24e404c0683409629fbe0a123/wal-000000013 (ops 60-64)
I20260812 06:19:18.426745 18713 log.cc:1079] T 2861e5e24e404c0683409629fbe0a123 P 81887ede3a4e4593a16078c62520fa94: Deleting log segment in path: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551012943-18375-0/minicluster-data/ts-0-root/wals/2861e5e24e404c0683409629fbe0a123/wal-000000014 (ops 65-69)
I20260812 06:19:18.455643 18713 maintenance_manager.cc:643] P 81887ede3a4e4593a16078c62520fa94: LogGCOp(2861e5e24e404c0683409629fbe0a123) complete. Timing: real 0.030s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:19:18.456077 18783 maintenance_manager.cc:419] P 81887ede3a4e4593a16078c62520fa94: Scheduling FlushDeltaMemStoresOp(2861e5e24e404c0683409629fbe0a123): perf score=2.188937
I20260812 06:19:18.478948 18713 maintenance_manager.cc:643] P 81887ede3a4e4593a16078c62520fa94: FlushDeltaMemStoresOp(2861e5e24e404c0683409629fbe0a123) complete. Timing: real 0.023s	user 0.003s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6537,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:18.479439 18783 maintenance_manager.cc:419] P 81887ede3a4e4593a16078c62520fa94: Scheduling UndoDeltaBlockGCOp(2861e5e24e404c0683409629fbe0a123): 472 bytes on disk
I20260812 06:19:18.479827 18713 maintenance_manager.cc:643] P 81887ede3a4e4593a16078c62520fa94: UndoDeltaBlockGCOp(2861e5e24e404c0683409629fbe0a123) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":48,"lbm_reads_lt_1ms":4}
I20260812 06:19:18.480273 18783 maintenance_manager.cc:419] P 81887ede3a4e4593a16078c62520fa94: Scheduling FlushDeltaMemStoresOp(2861e5e24e404c0683409629fbe0a123): perf score=2.188937
I20260812 06:19:18.490839 18713 maintenance_manager.cc:643] P 81887ede3a4e4593a16078c62520fa94: FlushDeltaMemStoresOp(2861e5e24e404c0683409629fbe0a123) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4222,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:18.491535 18783 maintenance_manager.cc:419] P 81887ede3a4e4593a16078c62520fa94: Scheduling MajorDeltaCompactionOp(2861e5e24e404c0683409629fbe0a123): perf score=1.000000
I20260812 06:19:18.754396 18713 maintenance_manager.cc:643] P 81887ede3a4e4593a16078c62520fa94: MajorDeltaCompactionOp(2861e5e24e404c0683409629fbe0a123) complete. Timing: real 0.263s	user 0.186s	sys 0.071s Metrics: {"cfile_cache_miss":835,"cfile_cache_miss_bytes":37082280,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":850,"lbm_read_time_us":19289,"lbm_reads_lt_1ms":875,"lbm_write_time_us":44388,"lbm_writes_lt_1ms":843,"mutex_wait_us":28,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":19712,"thread_start_us":85,"threads_started":1,"update_count":4000}
I20260812 06:19:18.755256 18783 maintenance_manager.cc:419] P 81887ede3a4e4593a16078c62520fa94: Scheduling FlushDeltaMemStoresOp(2861e5e24e404c0683409629fbe0a123): perf score=18.063937
I20260812 06:19:18.828873 18713 maintenance_manager.cc:643] P 81887ede3a4e4593a16078c62520fa94: FlushDeltaMemStoresOp(2861e5e24e404c0683409629fbe0a123) complete. Timing: real 0.068s	user 0.056s	sys 0.009s Metrics: {"bytes_written":20512314,"delete_count":0,"lbm_write_time_us":30850,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:18.829346 18783 maintenance_manager.cc:419] P 81887ede3a4e4593a16078c62520fa94: Scheduling FlushDeltaMemStoresOp(2861e5e24e404c0683409629fbe0a123): perf score=3.181125
I20260812 06:19:18.846043 18713 maintenance_manager.cc:643] P 81887ede3a4e4593a16078c62520fa94: FlushDeltaMemStoresOp(2861e5e24e404c0683409629fbe0a123) complete. Timing: real 0.017s	user 0.002s	sys 0.008s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4596,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:18.846490 18783 maintenance_manager.cc:419] P 81887ede3a4e4593a16078c62520fa94: Scheduling FlushDeltaMemStoresOp(2861e5e24e404c0683409629fbe0a123): perf score=2.188937
I20260812 06:19:18.856284 18713 maintenance_manager.cc:643] P 81887ede3a4e4593a16078c62520fa94: FlushDeltaMemStoresOp(2861e5e24e404c0683409629fbe0a123) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3694,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:18.856705 18783 maintenance_manager.cc:419] P 81887ede3a4e4593a16078c62520fa94: Scheduling MajorDeltaCompactionOp(2861e5e24e404c0683409629fbe0a123): perf score=1.000000
I20260812 06:19:19.075047 18713 maintenance_manager.cc:643] P 81887ede3a4e4593a16078c62520fa94: MajorDeltaCompactionOp(2861e5e24e404c0683409629fbe0a123) complete. Timing: real 0.218s	user 0.129s	sys 0.088s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":32979619,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":659,"lbm_read_time_us":16978,"lbm_reads_lt_1ms":773,"lbm_write_time_us":41778,"lbm_writes_lt_1ms":743,"mutex_wait_us":331,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":9472,"update_count":3500}
I20260812 06:19:19.077116 18783 maintenance_manager.cc:419] P 81887ede3a4e4593a16078c62520fa94: Scheduling FlushDeltaMemStoresOp(2861e5e24e404c0683409629fbe0a123): perf score=15.087375
I20260812 06:19:19.125511 18713 maintenance_manager.cc:643] P 81887ede3a4e4593a16078c62520fa94: FlushDeltaMemStoresOp(2861e5e24e404c0683409629fbe0a123) complete. Timing: real 0.048s	user 0.023s	sys 0.023s Metrics: {"bytes_written":16820142,"delete_count":0,"lbm_write_time_us":21016,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:19:19.126102 18783 maintenance_manager.cc:419] P 81887ede3a4e4593a16078c62520fa94: Scheduling FlushDeltaMemStoresOp(2861e5e24e404c0683409629fbe0a123): perf score=2.188937
I20260812 06:19:19.141497 18713 maintenance_manager.cc:643] P 81887ede3a4e4593a16078c62520fa94: FlushDeltaMemStoresOp(2861e5e24e404c0683409629fbe0a123) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5372,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:19.141997 18783 maintenance_manager.cc:419] P 81887ede3a4e4593a16078c62520fa94: Scheduling MajorDeltaCompactionOp(2861e5e24e404c0683409629fbe0a123): perf score=1.000000
I20260812 06:19:19.318986 18713 maintenance_manager.cc:643] P 81887ede3a4e4593a16078c62520fa94: MajorDeltaCompactionOp(2861e5e24e404c0683409629fbe0a123) complete. Timing: real 0.177s	user 0.134s	sys 0.029s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774675,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":930,"lbm_read_time_us":11677,"lbm_reads_lt_1ms":564,"lbm_write_time_us":32400,"lbm_writes_lt_1ms":543,"mutex_wait_us":585,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6912,"update_count":2500}
I20260812 06:19:19.319694 18783 maintenance_manager.cc:419] P 81887ede3a4e4593a16078c62520fa94: Scheduling FlushDeltaMemStoresOp(2861e5e24e404c0683409629fbe0a123): perf score=14.095187
I20260812 06:19:19.378453 18713 maintenance_manager.cc:643] P 81887ede3a4e4593a16078c62520fa94: FlushDeltaMemStoresOp(2861e5e24e404c0683409629fbe0a123) complete. Timing: real 0.059s	user 0.040s	sys 0.007s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23138,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:19.378898 18783 maintenance_manager.cc:419] P 81887ede3a4e4593a16078c62520fa94: Scheduling FlushDeltaMemStoresOp(2861e5e24e404c0683409629fbe0a123): perf score=2.188937
I20260812 06:19:19.391021 18713 maintenance_manager.cc:643] P 81887ede3a4e4593a16078c62520fa94: FlushDeltaMemStoresOp(2861e5e24e404c0683409629fbe0a123) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4139,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:19.391656 18783 maintenance_manager.cc:419] P 81887ede3a4e4593a16078c62520fa94: Scheduling MajorDeltaCompactionOp(2861e5e24e404c0683409629fbe0a123): perf score=1.000000
I20260812 06:19:19.590934 18713 maintenance_manager.cc:643] P 81887ede3a4e4593a16078c62520fa94: MajorDeltaCompactionOp(2861e5e24e404c0683409629fbe0a123) complete. Timing: real 0.199s	user 0.104s	sys 0.092s 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":341,"lbm_read_time_us":13862,"lbm_reads_lt_1ms":572,"lbm_write_time_us":32926,"lbm_writes_lt_1ms":543,"mutex_wait_us":21,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":13440,"update_count":2500}
I20260812 06:19:19.591681 18783 maintenance_manager.cc:419] P 81887ede3a4e4593a16078c62520fa94: Scheduling FlushDeltaMemStoresOp(2861e5e24e404c0683409629fbe0a123): perf score=14.095187
I20260812 06:19:19.640810 18713 maintenance_manager.cc:643] P 81887ede3a4e4593a16078c62520fa94: FlushDeltaMemStoresOp(2861e5e24e404c0683409629fbe0a123) complete. Timing: real 0.049s	user 0.024s	sys 0.023s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":21540,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:19.641355 18783 maintenance_manager.cc:419] P 81887ede3a4e4593a16078c62520fa94: Scheduling MajorDeltaCompactionOp(2861e5e24e404c0683409629fbe0a123): perf score=1.000000
I20260812 06:19:19.798013 18713 maintenance_manager.cc:643] P 81887ede3a4e4593a16078c62520fa94: MajorDeltaCompactionOp(2861e5e24e404c0683409629fbe0a123) complete. Timing: real 0.156s	user 0.122s	sys 0.033s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672159,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":257,"lbm_read_time_us":12314,"lbm_reads_lt_1ms":463,"lbm_write_time_us":25182,"lbm_writes_lt_1ms":443,"mutex_wait_us":73,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2000}
I20260812 06:19:19.798749 18783 maintenance_manager.cc:419] P 81887ede3a4e4593a16078c62520fa94: Scheduling FlushDeltaMemStoresOp(2861e5e24e404c0683409629fbe0a123): perf score=11.118625
I20260812 06:19:19.831821 18713 maintenance_manager.cc:643] P 81887ede3a4e4593a16078c62520fa94: FlushDeltaMemStoresOp(2861e5e24e404c0683409629fbe0a123) complete. Timing: real 0.033s	user 0.025s	sys 0.007s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":14029,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:19.832617 18783 maintenance_manager.cc:419] P 81887ede3a4e4593a16078c62520fa94: Scheduling FlushDeltaMemStoresOp(2861e5e24e404c0683409629fbe0a123): perf score=2.188937
I20260812 06:19:19.861490 18713 maintenance_manager.cc:643] P 81887ede3a4e4593a16078c62520fa94: FlushDeltaMemStoresOp(2861e5e24e404c0683409629fbe0a123) complete. Timing: real 0.029s	user 0.004s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5665,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:19.861975 18783 maintenance_manager.cc:419] P 81887ede3a4e4593a16078c62520fa94: Scheduling FlushDeltaMemStoresOp(2861e5e24e404c0683409629fbe0a123): perf score=2.188937
I20260812 06:19:19.877209 18713 maintenance_manager.cc:643] P 81887ede3a4e4593a16078c62520fa94: FlushDeltaMemStoresOp(2861e5e24e404c0683409629fbe0a123) complete. Timing: real 0.015s	user 0.004s	sys 0.009s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5963,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:19.877712 18783 maintenance_manager.cc:419] P 81887ede3a4e4593a16078c62520fa94: Scheduling FlushMRSOp(2861e5e24e404c0683409629fbe0a123): perf score=1.000000
I20260812 06:19:19.923702 18713 maintenance_manager.cc:643] P 81887ede3a4e4593a16078c62520fa94: FlushMRSOp(2861e5e24e404c0683409629fbe0a123) complete. Timing: real 0.046s	user 0.034s	sys 0.004s Metrics: {"bytes_written":1152514,"cfile_init":1,"dirs.queue_time_us":70,"dirs.run_cpu_time_us":231,"dirs.run_wall_time_us":1449,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1608,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:19:19.924484 18783 maintenance_manager.cc:419] P 81887ede3a4e4593a16078c62520fa94: Scheduling LogGCOp(2861e5e24e404c0683409629fbe0a123): free 115943182 bytes of WAL
I20260812 06:19:19.924733 18713 log_reader.cc:385] T 2861e5e24e404c0683409629fbe0a123: removed 11 log segments from log reader
I20260812 06:19:19.924808 18713 log.cc:1079] T 2861e5e24e404c0683409629fbe0a123 P 81887ede3a4e4593a16078c62520fa94: Deleting log segment in path: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551012943-18375-0/minicluster-data/ts-0-root/wals/2861e5e24e404c0683409629fbe0a123/wal-000000015 (ops 70-74)
I20260812 06:19:19.924861 18713 log.cc:1079] T 2861e5e24e404c0683409629fbe0a123 P 81887ede3a4e4593a16078c62520fa94: Deleting log segment in path: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551012943-18375-0/minicluster-data/ts-0-root/wals/2861e5e24e404c0683409629fbe0a123/wal-000000016 (ops 75-79)
I20260812 06:19:19.924932 18713 log.cc:1079] T 2861e5e24e404c0683409629fbe0a123 P 81887ede3a4e4593a16078c62520fa94: Deleting log segment in path: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551012943-18375-0/minicluster-data/ts-0-root/wals/2861e5e24e404c0683409629fbe0a123/wal-000000017 (ops 80-84)
I20260812 06:19:19.924973 18713 log.cc:1079] T 2861e5e24e404c0683409629fbe0a123 P 81887ede3a4e4593a16078c62520fa94: Deleting log segment in path: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551012943-18375-0/minicluster-data/ts-0-root/wals/2861e5e24e404c0683409629fbe0a123/wal-000000018 (ops 85-89)
I20260812 06:19:19.925009 18713 log.cc:1079] T 2861e5e24e404c0683409629fbe0a123 P 81887ede3a4e4593a16078c62520fa94: Deleting log segment in path: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551012943-18375-0/minicluster-data/ts-0-root/wals/2861e5e24e404c0683409629fbe0a123/wal-000000019 (ops 90-94)
I20260812 06:19:19.925046 18713 log.cc:1079] T 2861e5e24e404c0683409629fbe0a123 P 81887ede3a4e4593a16078c62520fa94: Deleting log segment in path: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551012943-18375-0/minicluster-data/ts-0-root/wals/2861e5e24e404c0683409629fbe0a123/wal-000000020 (ops 95-99)
I20260812 06:19:19.925083 18713 log.cc:1079] T 2861e5e24e404c0683409629fbe0a123 P 81887ede3a4e4593a16078c62520fa94: Deleting log segment in path: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551012943-18375-0/minicluster-data/ts-0-root/wals/2861e5e24e404c0683409629fbe0a123/wal-000000021 (ops 100-104)
I20260812 06:19:19.925120 18713 log.cc:1079] T 2861e5e24e404c0683409629fbe0a123 P 81887ede3a4e4593a16078c62520fa94: Deleting log segment in path: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551012943-18375-0/minicluster-data/ts-0-root/wals/2861e5e24e404c0683409629fbe0a123/wal-000000022 (ops 105-109)
I20260812 06:19:19.925156 18713 log.cc:1079] T 2861e5e24e404c0683409629fbe0a123 P 81887ede3a4e4593a16078c62520fa94: Deleting log segment in path: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551012943-18375-0/minicluster-data/ts-0-root/wals/2861e5e24e404c0683409629fbe0a123/wal-000000023 (ops 110-114)
I20260812 06:19:19.925194 18713 log.cc:1079] T 2861e5e24e404c0683409629fbe0a123 P 81887ede3a4e4593a16078c62520fa94: Deleting log segment in path: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551012943-18375-0/minicluster-data/ts-0-root/wals/2861e5e24e404c0683409629fbe0a123/wal-000000024 (ops 115-119)
I20260812 06:19:19.925230 18713 log.cc:1079] T 2861e5e24e404c0683409629fbe0a123 P 81887ede3a4e4593a16078c62520fa94: Deleting log segment in path: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551012943-18375-0/minicluster-data/ts-0-root/wals/2861e5e24e404c0683409629fbe0a123/wal-000000025 (ops 120-124)
I20260812 06:19:19.953486 18713 maintenance_manager.cc:643] P 81887ede3a4e4593a16078c62520fa94: LogGCOp(2861e5e24e404c0683409629fbe0a123) complete. Timing: real 0.029s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:19:19.953984 18783 maintenance_manager.cc:419] P 81887ede3a4e4593a16078c62520fa94: Scheduling FlushDeltaMemStoresOp(2861e5e24e404c0683409629fbe0a123): perf score=3.181125
I20260812 06:19:19.976804 18713 maintenance_manager.cc:643] P 81887ede3a4e4593a16078c62520fa94: FlushDeltaMemStoresOp(2861e5e24e404c0683409629fbe0a123) complete. Timing: real 0.023s	user 0.008s	sys 0.008s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":7192,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:19.977342 18783 maintenance_manager.cc:419] P 81887ede3a4e4593a16078c62520fa94: Scheduling UndoDeltaBlockGCOp(2861e5e24e404c0683409629fbe0a123): 448 bytes on disk
I20260812 06:19:19.977771 18713 maintenance_manager.cc:643] P 81887ede3a4e4593a16078c62520fa94: UndoDeltaBlockGCOp(2861e5e24e404c0683409629fbe0a123) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":51,"lbm_reads_lt_1ms":4}
I20260812 06:19:19.978276 18783 maintenance_manager.cc:419] P 81887ede3a4e4593a16078c62520fa94: Scheduling FlushDeltaMemStoresOp(2861e5e24e404c0683409629fbe0a123): perf score=2.188937
I20260812 06:19:19.988804 18713 maintenance_manager.cc:643] P 81887ede3a4e4593a16078c62520fa94: FlushDeltaMemStoresOp(2861e5e24e404c0683409629fbe0a123) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4191,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:19.989311 18783 maintenance_manager.cc:419] P 81887ede3a4e4593a16078c62520fa94: Scheduling MajorDeltaCompactionOp(2861e5e24e404c0683409629fbe0a123): perf score=1.000000
I20260812 06:19:20.219369 18713 maintenance_manager.cc:643] P 81887ede3a4e4593a16078c62520fa94: MajorDeltaCompactionOp(2861e5e24e404c0683409629fbe0a123) complete. Timing: real 0.229s	user 0.136s	sys 0.092s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32979847,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":704,"lbm_read_time_us":17784,"lbm_reads_lt_1ms":775,"lbm_write_time_us":37372,"lbm_writes_lt_1ms":743,"mutex_wait_us":114,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":6016,"thread_start_us":78,"threads_started":1,"update_count":3500}
I20260812 06:19:20.219957 18783 maintenance_manager.cc:419] P 81887ede3a4e4593a16078c62520fa94: Scheduling FlushDeltaMemStoresOp(2861e5e24e404c0683409629fbe0a123): perf score=18.063937
I20260812 06:19:20.292785 18713 maintenance_manager.cc:643] P 81887ede3a4e4593a16078c62520fa94: FlushDeltaMemStoresOp(2861e5e24e404c0683409629fbe0a123) complete. Timing: real 0.073s	user 0.044s	sys 0.017s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":31182,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":502,"reinsert_count":0,"update_count":2500}
I20260812 06:19:20.293304 18783 maintenance_manager.cc:419] P 81887ede3a4e4593a16078c62520fa94: Scheduling FlushDeltaMemStoresOp(2861e5e24e404c0683409629fbe0a123): perf score=2.188937
I20260812 06:19:20.305660 18713 maintenance_manager.cc:643] P 81887ede3a4e4593a16078c62520fa94: FlushDeltaMemStoresOp(2861e5e24e404c0683409629fbe0a123) complete. Timing: real 0.012s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4329,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:20.306180 18783 maintenance_manager.cc:419] P 81887ede3a4e4593a16078c62520fa94: Scheduling MajorDeltaCompactionOp(2861e5e24e404c0683409629fbe0a123): perf score=1.000000
I20260812 06:19:20.528584 18713 maintenance_manager.cc:643] P 81887ede3a4e4593a16078c62520fa94: MajorDeltaCompactionOp(2861e5e24e404c0683409629fbe0a123) complete. Timing: real 0.222s	user 0.147s	sys 0.075s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877104,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":297,"lbm_read_time_us":16638,"lbm_reads_lt_1ms":672,"lbm_write_time_us":34967,"lbm_writes_lt_1ms":643,"mutex_wait_us":33,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":5504,"update_count":3000}
I20260812 06:19:20.529196 18783 maintenance_manager.cc:419] P 81887ede3a4e4593a16078c62520fa94: Scheduling FlushDeltaMemStoresOp(2861e5e24e404c0683409629fbe0a123): perf score=18.063937
I20260812 06:19:20.599269 18713 maintenance_manager.cc:643] P 81887ede3a4e4593a16078c62520fa94: FlushDeltaMemStoresOp(2861e5e24e404c0683409629fbe0a123) complete. Timing: real 0.070s	user 0.044s	sys 0.012s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":25893,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:20.599722 18783 maintenance_manager.cc:419] P 81887ede3a4e4593a16078c62520fa94: Scheduling FlushDeltaMemStoresOp(2861e5e24e404c0683409629fbe0a123): perf score=2.188937
I20260812 06:19:20.611323 18713 maintenance_manager.cc:643] P 81887ede3a4e4593a16078c62520fa94: FlushDeltaMemStoresOp(2861e5e24e404c0683409629fbe0a123) complete. Timing: real 0.011s	user 0.008s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4261,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:20.611749 18783 maintenance_manager.cc:419] P 81887ede3a4e4593a16078c62520fa94: Scheduling MajorDeltaCompactionOp(2861e5e24e404c0683409629fbe0a123): perf score=1.000000
I20260812 06:19:20.818701 18713 maintenance_manager.cc:643] P 81887ede3a4e4593a16078c62520fa94: MajorDeltaCompactionOp(2861e5e24e404c0683409629fbe0a123) complete. Timing: real 0.207s	user 0.129s	sys 0.076s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877103,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":186,"lbm_read_time_us":16851,"lbm_reads_lt_1ms":672,"lbm_write_time_us":33917,"lbm_writes_lt_1ms":643,"mutex_wait_us":29,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":24576,"update_count":3000}
I20260812 06:19:20.819757 18783 maintenance_manager.cc:419] P 81887ede3a4e4593a16078c62520fa94: Scheduling FlushDeltaMemStoresOp(2861e5e24e404c0683409629fbe0a123): perf score=16.079562
I20260812 06:19:20.887313 18713 maintenance_manager.cc:643] P 81887ede3a4e4593a16078c62520fa94: FlushDeltaMemStoresOp(2861e5e24e404c0683409629fbe0a123) complete. Timing: real 0.067s	user 0.041s	sys 0.021s Metrics: {"bytes_written":18666229,"delete_count":0,"lbm_write_time_us":28195,"lbm_writes_lt_1ms":458,"reinsert_count":0,"update_count":2275}
I20260812 06:19:20.887773 18783 maintenance_manager.cc:419] P 81887ede3a4e4593a16078c62520fa94: Scheduling FlushDeltaMemStoresOp(2861e5e24e404c0683409629fbe0a123): perf score=4.173312
I20260812 06:19:20.905598 18713 maintenance_manager.cc:643] P 81887ede3a4e4593a16078c62520fa94: FlushDeltaMemStoresOp(2861e5e24e404c0683409629fbe0a123) complete. Timing: real 0.018s	user 0.007s	sys 0.008s Metrics: {"bytes_written":5948756,"delete_count":0,"lbm_write_time_us":7132,"lbm_writes_lt_1ms":148,"reinsert_count":0,"update_count":725}
I20260812 06:19:20.906082 18783 maintenance_manager.cc:419] P 81887ede3a4e4593a16078c62520fa94: Scheduling MajorDeltaCompactionOp(2861e5e24e404c0683409629fbe0a123): perf score=1.000000
I20260812 06:19:21.117755 18713 maintenance_manager.cc:643] P 81887ede3a4e4593a16078c62520fa94: MajorDeltaCompactionOp(2861e5e24e404c0683409629fbe0a123) complete. Timing: real 0.211s	user 0.136s	sys 0.076s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877107,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":373,"lbm_read_time_us":17186,"lbm_reads_lt_1ms":664,"lbm_write_time_us":34257,"lbm_writes_lt_1ms":643,"mutex_wait_us":62,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":27904,"update_count":3000}
I20260812 06:19:21.118428 18783 maintenance_manager.cc:419] P 81887ede3a4e4593a16078c62520fa94: Scheduling FlushDeltaMemStoresOp(2861e5e24e404c0683409629fbe0a123): perf score=14.095187
I20260812 06:19:21.178915 18713 maintenance_manager.cc:643] P 81887ede3a4e4593a16078c62520fa94: FlushDeltaMemStoresOp(2861e5e24e404c0683409629fbe0a123) complete. Timing: real 0.060s	user 0.026s	sys 0.027s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":27024,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:21.179468 18783 maintenance_manager.cc:419] P 81887ede3a4e4593a16078c62520fa94: Scheduling FlushDeltaMemStoresOp(2861e5e24e404c0683409629fbe0a123): perf score=2.188937
I20260812 06:19:21.194911 18713 maintenance_manager.cc:643] P 81887ede3a4e4593a16078c62520fa94: FlushDeltaMemStoresOp(2861e5e24e404c0683409629fbe0a123) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6001,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:21.195511 18783 maintenance_manager.cc:419] P 81887ede3a4e4593a16078c62520fa94: Scheduling MajorDeltaCompactionOp(2861e5e24e404c0683409629fbe0a123): perf score=1.000000
I20260812 06:19:21.378386 18713 maintenance_manager.cc:643] P 81887ede3a4e4593a16078c62520fa94: MajorDeltaCompactionOp(2861e5e24e404c0683409629fbe0a123) complete. Timing: real 0.183s	user 0.138s	sys 0.044s 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":172,"lbm_read_time_us":14586,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31145,"lbm_writes_lt_1ms":543,"mutex_wait_us":21,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14976,"update_count":2500}
I20260812 06:19:21.379077 18783 maintenance_manager.cc:419] P 81887ede3a4e4593a16078c62520fa94: Scheduling FlushDeltaMemStoresOp(2861e5e24e404c0683409629fbe0a123): perf score=14.095187
I20260812 06:19:21.446173 18713 maintenance_manager.cc:643] P 81887ede3a4e4593a16078c62520fa94: FlushDeltaMemStoresOp(2861e5e24e404c0683409629fbe0a123) complete. Timing: real 0.067s	user 0.028s	sys 0.036s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":25754,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:21.446776 18783 maintenance_manager.cc:419] P 81887ede3a4e4593a16078c62520fa94: Scheduling FlushDeltaMemStoresOp(2861e5e24e404c0683409629fbe0a123): perf score=2.188937
I20260812 06:19:21.462432 18713 maintenance_manager.cc:643] P 81887ede3a4e4593a16078c62520fa94: FlushDeltaMemStoresOp(2861e5e24e404c0683409629fbe0a123) complete. Timing: real 0.015s	user 0.011s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6331,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:21.462965 18783 maintenance_manager.cc:419] P 81887ede3a4e4593a16078c62520fa94: Scheduling FlushMRSOp(2861e5e24e404c0683409629fbe0a123): perf score=1.000000
I20260812 06:19:21.504940 18713 maintenance_manager.cc:643] P 81887ede3a4e4593a16078c62520fa94: FlushMRSOp(2861e5e24e404c0683409629fbe0a123) complete. Timing: real 0.042s	user 0.026s	sys 0.000s Metrics: {"bytes_written":1234475,"cfile_init":1,"dirs.queue_time_us":79,"dirs.run_cpu_time_us":227,"dirs.run_wall_time_us":1480,"drs_written":1,"lbm_read_time_us":63,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1556,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:19:21.505709 18783 maintenance_manager.cc:419] P 81887ede3a4e4593a16078c62520fa94: Scheduling LogGCOp(2861e5e24e404c0683409629fbe0a123): free 128867710 bytes of WAL
I20260812 06:19:21.505956 18713 log_reader.cc:385] T 2861e5e24e404c0683409629fbe0a123: removed 13 log segments from log reader
I20260812 06:19:21.506007 18713 log.cc:1079] T 2861e5e24e404c0683409629fbe0a123 P 81887ede3a4e4593a16078c62520fa94: Deleting log segment in path: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551012943-18375-0/minicluster-data/ts-0-root/wals/2861e5e24e404c0683409629fbe0a123/wal-000000026 (ops 125-129)
I20260812 06:19:21.506036 18713 log.cc:1079] T 2861e5e24e404c0683409629fbe0a123 P 81887ede3a4e4593a16078c62520fa94: Deleting log segment in path: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551012943-18375-0/minicluster-data/ts-0-root/wals/2861e5e24e404c0683409629fbe0a123/wal-000000027 (ops 130-134)
I20260812 06:19:21.506102 18713 log.cc:1079] T 2861e5e24e404c0683409629fbe0a123 P 81887ede3a4e4593a16078c62520fa94: Deleting log segment in path: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551012943-18375-0/minicluster-data/ts-0-root/wals/2861e5e24e404c0683409629fbe0a123/wal-000000028 (ops 135-139)
I20260812 06:19:21.506132 18713 log.cc:1079] T 2861e5e24e404c0683409629fbe0a123 P 81887ede3a4e4593a16078c62520fa94: Deleting log segment in path: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551012943-18375-0/minicluster-data/ts-0-root/wals/2861e5e24e404c0683409629fbe0a123/wal-000000029 (ops 140-144)
I20260812 06:19:21.506175 18713 log.cc:1079] T 2861e5e24e404c0683409629fbe0a123 P 81887ede3a4e4593a16078c62520fa94: Deleting log segment in path: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551012943-18375-0/minicluster-data/ts-0-root/wals/2861e5e24e404c0683409629fbe0a123/wal-000000030 (ops 145-148)
I20260812 06:19:21.506209 18713 log.cc:1079] T 2861e5e24e404c0683409629fbe0a123 P 81887ede3a4e4593a16078c62520fa94: Deleting log segment in path: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551012943-18375-0/minicluster-data/ts-0-root/wals/2861e5e24e404c0683409629fbe0a123/wal-000000031 (ops 149-153)
I20260812 06:19:21.506250 18713 log.cc:1079] T 2861e5e24e404c0683409629fbe0a123 P 81887ede3a4e4593a16078c62520fa94: Deleting log segment in path: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551012943-18375-0/minicluster-data/ts-0-root/wals/2861e5e24e404c0683409629fbe0a123/wal-000000032 (ops 154-158)
I20260812 06:19:21.506291 18713 log.cc:1079] T 2861e5e24e404c0683409629fbe0a123 P 81887ede3a4e4593a16078c62520fa94: Deleting log segment in path: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551012943-18375-0/minicluster-data/ts-0-root/wals/2861e5e24e404c0683409629fbe0a123/wal-000000033 (ops 159-163)
I20260812 06:19:21.506333 18713 log.cc:1079] T 2861e5e24e404c0683409629fbe0a123 P 81887ede3a4e4593a16078c62520fa94: Deleting log segment in path: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551012943-18375-0/minicluster-data/ts-0-root/wals/2861e5e24e404c0683409629fbe0a123/wal-000000034 (ops 164-168)
I20260812 06:19:21.506371 18713 log.cc:1079] T 2861e5e24e404c0683409629fbe0a123 P 81887ede3a4e4593a16078c62520fa94: Deleting log segment in path: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551012943-18375-0/minicluster-data/ts-0-root/wals/2861e5e24e404c0683409629fbe0a123/wal-000000035 (ops 169-172)
I20260812 06:19:21.506412 18713 log.cc:1079] T 2861e5e24e404c0683409629fbe0a123 P 81887ede3a4e4593a16078c62520fa94: Deleting log segment in path: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551012943-18375-0/minicluster-data/ts-0-root/wals/2861e5e24e404c0683409629fbe0a123/wal-000000036 (ops 173-177)
I20260812 06:19:21.506450 18713 log.cc:1079] T 2861e5e24e404c0683409629fbe0a123 P 81887ede3a4e4593a16078c62520fa94: Deleting log segment in path: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551012943-18375-0/minicluster-data/ts-0-root/wals/2861e5e24e404c0683409629fbe0a123/wal-000000037 (ops 178-182)
I20260812 06:19:21.506490 18713 log.cc:1079] T 2861e5e24e404c0683409629fbe0a123 P 81887ede3a4e4593a16078c62520fa94: Deleting log segment in path: /tmp/dist-test-taskCESijU/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515551012943-18375-0/minicluster-data/ts-0-root/wals/2861e5e24e404c0683409629fbe0a123/wal-000000038 (ops 183-186)
I20260812 06:19:21.537807 18713 maintenance_manager.cc:643] P 81887ede3a4e4593a16078c62520fa94: LogGCOp(2861e5e24e404c0683409629fbe0a123) complete. Timing: real 0.032s	user 0.000s	sys 0.029s Metrics: {}
I20260812 06:19:21.538529 18783 maintenance_manager.cc:419] P 81887ede3a4e4593a16078c62520fa94: Scheduling UndoDeltaBlockGCOp(2861e5e24e404c0683409629fbe0a123): 472 bytes on disk
I20260812 06:19:21.538993 18713 maintenance_manager.cc:643] P 81887ede3a4e4593a16078c62520fa94: UndoDeltaBlockGCOp(2861e5e24e404c0683409629fbe0a123) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4}
I20260812 06:19:21.539683 18783 maintenance_manager.cc:419] P 81887ede3a4e4593a16078c62520fa94: Scheduling FlushDeltaMemStoresOp(2861e5e24e404c0683409629fbe0a123): perf score=5.165500
I20260812 06:19:21.561501 18713 maintenance_manager.cc:643] P 81887ede3a4e4593a16078c62520fa94: FlushDeltaMemStoresOp(2861e5e24e404c0683409629fbe0a123) complete. Timing: real 0.022s	user 0.019s	sys 0.000s Metrics: {"bytes_written":6851279,"delete_count":0,"lbm_write_time_us":8948,"lbm_writes_lt_1ms":170,"reinsert_count":0,"update_count":835}
I20260812 06:19:21.562114 18783 maintenance_manager.cc:419] P 81887ede3a4e4593a16078c62520fa94: Scheduling FlushDeltaMemStoresOp(2861e5e24e404c0683409629fbe0a123): perf score=1.000000
I20260812 06:19:21.570086 18713 maintenance_manager.cc:643] P 81887ede3a4e4593a16078c62520fa94: FlushDeltaMemStoresOp(2861e5e24e404c0683409629fbe0a123) complete. Timing: real 0.008s	user 0.000s	sys 0.006s Metrics: {"bytes_written":1353977,"delete_count":0,"lbm_write_time_us":2470,"lbm_writes_lt_1ms":36,"reinsert_count":0,"update_count":165}
I20260812 06:19:21.570547 18783 maintenance_manager.cc:419] P 81887ede3a4e4593a16078c62520fa94: Scheduling MajorDeltaCompactionOp(2861e5e24e404c0683409629fbe0a123): perf score=1.000000
I20260812 06:19:21.798105 18713 maintenance_manager.cc:643] P 81887ede3a4e4593a16078c62520fa94: MajorDeltaCompactionOp(2861e5e24e404c0683409629fbe0a123) complete. Timing: real 0.227s	user 0.143s	sys 0.084s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979682,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1266,"lbm_read_time_us":16256,"lbm_reads_lt_1ms":770,"lbm_write_time_us":41183,"lbm_writes_lt_1ms":743,"mutex_wait_us":305,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":6656,"thread_start_us":77,"threads_started":1,"update_count":3500}
I20260812 06:19:21.799489 18783 maintenance_manager.cc:419] P 81887ede3a4e4593a16078c62520fa94: Scheduling FlushDeltaMemStoresOp(2861e5e24e404c0683409629fbe0a123): perf score=18.063937
I20260812 06:19:21.839534 18375 heavy-update-compaction-itest.cc:229] Time spent updating: real 5.028s	user 1.849s	sys 0.188s
I20260812 06:19:21.849910 18713 maintenance_manager.cc:643] P 81887ede3a4e4593a16078c62520fa94: FlushDeltaMemStoresOp(2861e5e24e404c0683409629fbe0a123) complete. Timing: real 0.050s	user 0.029s	sys 0.020s Metrics: {"bytes_written":20512318,"delete_count":0,"lbm_write_time_us":24409,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:19:21.850438 18783 maintenance_manager.cc:419] P 81887ede3a4e4593a16078c62520fa94: Scheduling FlushDeltaMemStoresOp(2861e5e24e404c0683409629fbe0a123): perf score=2.188937
I20260812 06:19:21.860131 18713 maintenance_manager.cc:643] P 81887ede3a4e4593a16078c62520fa94: FlushDeltaMemStoresOp(2861e5e24e404c0683409629fbe0a123) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4115,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:21.860560 18783 maintenance_manager.cc:419] P 81887ede3a4e4593a16078c62520fa94: Scheduling MajorDeltaCompactionOp(2861e5e24e404c0683409629fbe0a123): perf score=1.000000
I20260812 06:19:21.875564 18375 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.036s	user 0.004s	sys 0.000s
I20260812 06:19:21.876149 18375 tablet_server.cc:179] TabletServer@127.17.241.193:0 shutting down...
I20260812 06:19:22.012465 18713 maintenance_manager.cc:643] P 81887ede3a4e4593a16078c62520fa94: MajorDeltaCompactionOp(2861e5e24e404c0683409629fbe0a123) complete. Timing: real 0.152s	user 0.083s	sys 0.067s Metrics: {"cfile_cache_hit":30,"cfile_cache_hit_bytes":4262390,"cfile_cache_miss":602,"cfile_cache_miss_bytes":24614715,"cfile_init":4,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":217,"lbm_read_time_us":11182,"lbm_reads_lt_1ms":618,"lbm_write_time_us":30055,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"update_count":3000}
I20260812 06:19:22.013804 18375 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:22.014210 18375 tablet_replica.cc:333] T 2861e5e24e404c0683409629fbe0a123 P 81887ede3a4e4593a16078c62520fa94: stopping tablet replica
I20260812 06:19:22.014376 18375 raft_consensus.cc:2243] T 2861e5e24e404c0683409629fbe0a123 P 81887ede3a4e4593a16078c62520fa94 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:22.014565 18375 raft_consensus.cc:2272] T 2861e5e24e404c0683409629fbe0a123 P 81887ede3a4e4593a16078c62520fa94 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:22.018981 18375 tablet_server.cc:196] TabletServer@127.17.241.193:0 shutdown complete.
I20260812 06:19:22.064639 18375 master.cc:562] Master@127.17.241.254:46165 shutting down...
I20260812 06:19:22.067924 18375 raft_consensus.cc:2243] T 00000000000000000000000000000000 P b38ce6d616604dacbb8a7c650472ab75 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:22.068132 18375 raft_consensus.cc:2272] T 00000000000000000000000000000000 P b38ce6d616604dacbb8a7c650472ab75 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:22.068235 18375 tablet_replica.cc:333] T 00000000000000000000000000000000 P b38ce6d616604dacbb8a7c650472ab75: stopping tablet replica
I20260812 06:19:22.080600 18375 master.cc:584] Master@127.17.241.254:46165 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5587 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11154 ms total)

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