[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:16:26.896607  6856 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.6.178.62:38079
I20260812 06:16:26.897493  6856 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:16:26.898011  6856 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:26.903402  6862 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:16:26.903524  6869 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:16:26.903671  6856 server_base.cc:1061] running on GCE node
W20260812 06:16:26.903697  6867 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:16:26.904125  6856 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:26.904235  6856 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:16:26.904275  6856 hybrid_clock.cc:648] HybridClock initialized: now 1786515386904273 us; error 0 us; skew 500 ppm
I20260812 06:16:26.905817  6856 webserver.cc:533] Webserver started at http://127.6.178.62:45199/ using document root <none> and password file <none>
I20260812 06:16:26.906276  6856 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:26.906338  6856 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:26.906533  6856 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:26.908015  6856 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386886772-6856-0/minicluster-data/master-0-root/instance:
uuid: "39efb4aaeb49450d8b3ebe58cad89e5a"
format_stamp: "Formatted at 2026-08-12 06:16:26 on dist-test-slave-42z9"
I20260812 06:16:26.911108  6856 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.005s	sys 0.000s
I20260812 06:16:26.912842  6877 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:26.913738  6856 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:16:26.913836  6856 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386886772-6856-0/minicluster-data/master-0-root
uuid: "39efb4aaeb49450d8b3ebe58cad89e5a"
format_stamp: "Formatted at 2026-08-12 06:16:26 on dist-test-slave-42z9"
I20260812 06:16:26.913914  6856 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386886772-6856-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386886772-6856-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386886772-6856-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:16:26.924731  6856 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:26.925235  6856 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:16:26.925369  6856 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:26.932147  6965 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.6.178.62:38079 every 8 connection(s)
I20260812 06:16:26.932147  6856 rpc_server.cc:307] RPC server started. Bound to: 127.6.178.62:38079
I20260812 06:16:26.934119  6966 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:16:26.938949  6966 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 39efb4aaeb49450d8b3ebe58cad89e5a: Bootstrap starting.
I20260812 06:16:26.940992  6966 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 39efb4aaeb49450d8b3ebe58cad89e5a: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:26.941777  6966 log.cc:826] T 00000000000000000000000000000000 P 39efb4aaeb49450d8b3ebe58cad89e5a: Log is configured to *not* fsync() on all Append() calls
I20260812 06:16:26.943157  6966 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 39efb4aaeb49450d8b3ebe58cad89e5a: No bootstrap required, opened a new log
I20260812 06:16:26.945636  6966 raft_consensus.cc:359] T 00000000000000000000000000000000 P 39efb4aaeb49450d8b3ebe58cad89e5a [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "39efb4aaeb49450d8b3ebe58cad89e5a" member_type: VOTER }
I20260812 06:16:26.945781  6966 raft_consensus.cc:385] T 00000000000000000000000000000000 P 39efb4aaeb49450d8b3ebe58cad89e5a [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:26.945824  6966 raft_consensus.cc:740] T 00000000000000000000000000000000 P 39efb4aaeb49450d8b3ebe58cad89e5a [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 39efb4aaeb49450d8b3ebe58cad89e5a, State: Initialized, Role: FOLLOWER
I20260812 06:16:26.946280  6966 consensus_queue.cc:260] T 00000000000000000000000000000000 P 39efb4aaeb49450d8b3ebe58cad89e5a [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: "39efb4aaeb49450d8b3ebe58cad89e5a" member_type: VOTER }
I20260812 06:16:26.946398  6966 raft_consensus.cc:399] T 00000000000000000000000000000000 P 39efb4aaeb49450d8b3ebe58cad89e5a [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:26.946439  6966 raft_consensus.cc:493] T 00000000000000000000000000000000 P 39efb4aaeb49450d8b3ebe58cad89e5a [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:26.946518  6966 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 39efb4aaeb49450d8b3ebe58cad89e5a [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:26.947162  6966 raft_consensus.cc:515] T 00000000000000000000000000000000 P 39efb4aaeb49450d8b3ebe58cad89e5a [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "39efb4aaeb49450d8b3ebe58cad89e5a" member_type: VOTER }
I20260812 06:16:26.947508  6966 leader_election.cc:304] T 00000000000000000000000000000000 P 39efb4aaeb49450d8b3ebe58cad89e5a [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: 39efb4aaeb49450d8b3ebe58cad89e5a; no voters: 
I20260812 06:16:26.947731  6966 leader_election.cc:290] T 00000000000000000000000000000000 P 39efb4aaeb49450d8b3ebe58cad89e5a [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:26.947836  6970 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 39efb4aaeb49450d8b3ebe58cad89e5a [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:26.948031  6970 raft_consensus.cc:697] T 00000000000000000000000000000000 P 39efb4aaeb49450d8b3ebe58cad89e5a [term 1 LEADER]: Becoming Leader. State: Replica: 39efb4aaeb49450d8b3ebe58cad89e5a, State: Running, Role: LEADER
I20260812 06:16:26.948426  6970 consensus_queue.cc:237] T 00000000000000000000000000000000 P 39efb4aaeb49450d8b3ebe58cad89e5a [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: "39efb4aaeb49450d8b3ebe58cad89e5a" member_type: VOTER }
I20260812 06:16:26.948526  6966 sys_catalog.cc:565] T 00000000000000000000000000000000 P 39efb4aaeb49450d8b3ebe58cad89e5a [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:16:26.949981  6972 sys_catalog.cc:455] T 00000000000000000000000000000000 P 39efb4aaeb49450d8b3ebe58cad89e5a [sys.catalog]: SysCatalogTable state changed. Reason: New leader 39efb4aaeb49450d8b3ebe58cad89e5a. Latest consensus state: current_term: 1 leader_uuid: "39efb4aaeb49450d8b3ebe58cad89e5a" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "39efb4aaeb49450d8b3ebe58cad89e5a" member_type: VOTER } }
I20260812 06:16:26.950079  6972 sys_catalog.cc:458] T 00000000000000000000000000000000 P 39efb4aaeb49450d8b3ebe58cad89e5a [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:26.950038  6971 sys_catalog.cc:455] T 00000000000000000000000000000000 P 39efb4aaeb49450d8b3ebe58cad89e5a [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "39efb4aaeb49450d8b3ebe58cad89e5a" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "39efb4aaeb49450d8b3ebe58cad89e5a" member_type: VOTER } }
I20260812 06:16:26.950155  6971 sys_catalog.cc:458] T 00000000000000000000000000000000 P 39efb4aaeb49450d8b3ebe58cad89e5a [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:26.950661  6856 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
W20260812 06:16:26.952430  6992 catalog_manager.cc:1594] T 00000000000000000000000000000000 P 39efb4aaeb49450d8b3ebe58cad89e5a: loading cluster ID for follower catalog manager: Not found: cluster ID entry not found
W20260812 06:16:26.952512  6992 catalog_manager.cc:883] Not found: cluster ID entry not found: failed to prepare follower catalog manager, will retry
I20260812 06:16:26.952572  6986 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:16:26.953392  6986 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:16:26.958031  6986 catalog_manager.cc:1383] Generated new cluster ID: 15a34165e21448e4b779c8426bd2e63b
I20260812 06:16:26.958102  6986 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:16:26.976837  6986 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:16:26.977564  6986 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:16:26.985695  6986 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 39efb4aaeb49450d8b3ebe58cad89e5a: Generated new TSK 0
I20260812 06:16:26.986181  6986 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:16:27.015137  6856 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:27.017611  7003 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:16:27.017707  7000 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:16:27.017608  7010 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:16:27.018042  6856 server_base.cc:1061] running on GCE node
I20260812 06:16:27.018218  6856 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:27.018265  6856 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:16:27.018292  6856 hybrid_clock.cc:648] HybridClock initialized: now 1786515387018292 us; error 0 us; skew 500 ppm
I20260812 06:16:27.019140  6856 webserver.cc:533] Webserver started at http://127.6.178.1:36097/ using document root <none> and password file <none>
I20260812 06:16:27.019292  6856 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:27.019346  6856 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:27.019433  6856 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:27.019850  6856 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386886772-6856-0/minicluster-data/ts-0-root/instance:
uuid: "980c963649d04baea69021b1b0a8384b"
format_stamp: "Formatted at 2026-08-12 06:16:27 on dist-test-slave-42z9"
I20260812 06:16:27.021571  6856 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.001s
I20260812 06:16:27.022593  7019 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:27.022840  6856 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:16:27.022908  6856 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386886772-6856-0/minicluster-data/ts-0-root
uuid: "980c963649d04baea69021b1b0a8384b"
format_stamp: "Formatted at 2026-08-12 06:16:27 on dist-test-slave-42z9"
I20260812 06:16:27.022975  6856 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386886772-6856-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386886772-6856-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386886772-6856-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:16:27.038144  6856 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:27.038507  6856 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:27.038941  6856 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:16:27.039723  6856 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:16:27.039772  6856 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:27.039815  6856 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:16:27.039845  6856 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:27.045789  6856 rpc_server.cc:307] RPC server started. Bound to: 127.6.178.1:46875
I20260812 06:16:27.045940  7110 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.6.178.1:46875 every 8 connection(s)
I20260812 06:16:27.058256  7111 heartbeater.cc:344] Connected to a master server at 127.6.178.62:38079
I20260812 06:16:27.058482  7111 heartbeater.cc:461] Registering TS with master...
I20260812 06:16:27.058914  7111 heartbeater.cc:507] Master 127.6.178.62:38079 requested a full tablet report, sending...
I20260812 06:16:27.060277  6907 ts_manager.cc:194] Registered new tserver with Master: 980c963649d04baea69021b1b0a8384b (127.6.178.1:46875)
I20260812 06:16:27.060881  6856 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.014504779s
I20260812 06:16:27.061391  6907 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:41482
I20260812 06:16:27.070298  6907 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:41488:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:16:27.085546  7054 tablet_service.cc:1511] Processing CreateTablet for tablet c16a6eddbf5045db853a30cd2752fdb7 (DEFAULT_TABLE table=heavy-update-compaction-test [id=ad46a9c49e544d49800b9cb90315574b]), partition=
I20260812 06:16:27.085987  7054 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet c16a6eddbf5045db853a30cd2752fdb7. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:16:27.089408  7132 tablet_bootstrap.cc:492] T c16a6eddbf5045db853a30cd2752fdb7 P 980c963649d04baea69021b1b0a8384b: Bootstrap starting.
I20260812 06:16:27.091568  7132 tablet_bootstrap.cc:654] T c16a6eddbf5045db853a30cd2752fdb7 P 980c963649d04baea69021b1b0a8384b: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:27.094417  7132 tablet_bootstrap.cc:492] T c16a6eddbf5045db853a30cd2752fdb7 P 980c963649d04baea69021b1b0a8384b: No bootstrap required, opened a new log
I20260812 06:16:27.094537  7132 ts_tablet_manager.cc:1403] T c16a6eddbf5045db853a30cd2752fdb7 P 980c963649d04baea69021b1b0a8384b: Time spent bootstrapping tablet: real 0.005s	user 0.000s	sys 0.004s
I20260812 06:16:27.095568  7132 raft_consensus.cc:359] T c16a6eddbf5045db853a30cd2752fdb7 P 980c963649d04baea69021b1b0a8384b [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "980c963649d04baea69021b1b0a8384b" member_type: VOTER last_known_addr { host: "127.6.178.1" port: 46875 } }
I20260812 06:16:27.095705  7132 raft_consensus.cc:385] T c16a6eddbf5045db853a30cd2752fdb7 P 980c963649d04baea69021b1b0a8384b [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:27.095749  7132 raft_consensus.cc:740] T c16a6eddbf5045db853a30cd2752fdb7 P 980c963649d04baea69021b1b0a8384b [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 980c963649d04baea69021b1b0a8384b, State: Initialized, Role: FOLLOWER
I20260812 06:16:27.095882  7132 consensus_queue.cc:260] T c16a6eddbf5045db853a30cd2752fdb7 P 980c963649d04baea69021b1b0a8384b [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: "980c963649d04baea69021b1b0a8384b" member_type: VOTER last_known_addr { host: "127.6.178.1" port: 46875 } }
I20260812 06:16:27.095989  7132 raft_consensus.cc:399] T c16a6eddbf5045db853a30cd2752fdb7 P 980c963649d04baea69021b1b0a8384b [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:27.096032  7132 raft_consensus.cc:493] T c16a6eddbf5045db853a30cd2752fdb7 P 980c963649d04baea69021b1b0a8384b [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:27.096081  7132 raft_consensus.cc:3060] T c16a6eddbf5045db853a30cd2752fdb7 P 980c963649d04baea69021b1b0a8384b [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:27.097597  7132 raft_consensus.cc:515] T c16a6eddbf5045db853a30cd2752fdb7 P 980c963649d04baea69021b1b0a8384b [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "980c963649d04baea69021b1b0a8384b" member_type: VOTER last_known_addr { host: "127.6.178.1" port: 46875 } }
I20260812 06:16:27.097743  7132 leader_election.cc:304] T c16a6eddbf5045db853a30cd2752fdb7 P 980c963649d04baea69021b1b0a8384b [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: 980c963649d04baea69021b1b0a8384b; no voters: 
I20260812 06:16:27.097980  7132 leader_election.cc:290] T c16a6eddbf5045db853a30cd2752fdb7 P 980c963649d04baea69021b1b0a8384b [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:27.098268  7136 raft_consensus.cc:2804] T c16a6eddbf5045db853a30cd2752fdb7 P 980c963649d04baea69021b1b0a8384b [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:27.098322  7132 ts_tablet_manager.cc:1434] T c16a6eddbf5045db853a30cd2752fdb7 P 980c963649d04baea69021b1b0a8384b: Time spent starting tablet: real 0.004s	user 0.000s	sys 0.004s
I20260812 06:16:27.098635  7111 heartbeater.cc:499] Master 127.6.178.62:38079 was elected leader, sending a full tablet report...
I20260812 06:16:27.098964  7136 raft_consensus.cc:697] T c16a6eddbf5045db853a30cd2752fdb7 P 980c963649d04baea69021b1b0a8384b [term 1 LEADER]: Becoming Leader. State: Replica: 980c963649d04baea69021b1b0a8384b, State: Running, Role: LEADER
I20260812 06:16:27.099125  7136 consensus_queue.cc:237] T c16a6eddbf5045db853a30cd2752fdb7 P 980c963649d04baea69021b1b0a8384b [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: "980c963649d04baea69021b1b0a8384b" member_type: VOTER last_known_addr { host: "127.6.178.1" port: 46875 } }
I20260812 06:16:27.101769  6907 catalog_manager.cc:5719] T c16a6eddbf5045db853a30cd2752fdb7 P 980c963649d04baea69021b1b0a8384b reported cstate change: term changed from 0 to 1, leader changed from <none> to 980c963649d04baea69021b1b0a8384b (127.6.178.1). New cstate: current_term: 1 leader_uuid: "980c963649d04baea69021b1b0a8384b" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "980c963649d04baea69021b1b0a8384b" member_type: VOTER last_known_addr { host: "127.6.178.1" port: 46875 } health_report { overall_health: HEALTHY } } }
I20260812 06:16:27.267155  6856 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.155s	user 0.012s	sys 0.022s
I20260812 06:16:27.296756  7112 maintenance_manager.cc:419] P 980c963649d04baea69021b1b0a8384b: Scheduling FlushMRSOp(c16a6eddbf5045db853a30cd2752fdb7): perf score=3.179940
I20260812 06:16:27.418903  7026 maintenance_manager.cc:643] P 980c963649d04baea69021b1b0a8384b: FlushMRSOp(c16a6eddbf5045db853a30cd2752fdb7) complete. Timing: real 0.122s	user 0.054s	sys 0.064s Metrics: {"bytes_written":4102659,"cfile_init":1,"compiler_manager_pool.queue_time_us":199,"delete_count":0,"dirs.queue_time_us":1116,"dirs.run_cpu_time_us":234,"dirs.run_wall_time_us":959,"drs_written":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4,"lbm_write_time_us":44766,"lbm_writes_1-10_ms":14,"lbm_writes_lt_1ms":153,"peak_mem_usage":0,"reinsert_count":0,"rows_written":101,"spinlock_wait_cycles":87296,"thread_start_us":123,"threads_started":1,"update_count":500}
I20260812 06:16:27.420274  7112 maintenance_manager.cc:419] P 980c963649d04baea69021b1b0a8384b: Scheduling MajorDeltaCompactionOp(c16a6eddbf5045db853a30cd2752fdb7): perf score=0.990968
I20260812 06:16:27.523666  7026 maintenance_manager.cc:643] P 980c963649d04baea69021b1b0a8384b: MajorDeltaCompactionOp(c16a6eddbf5045db853a30cd2752fdb7) complete. Timing: real 0.103s	user 0.067s	sys 0.035s Metrics: {"cfile_cache_miss":131,"cfile_cache_miss_bytes":8242026,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":264,"lbm_read_time_us":4005,"lbm_reads_lt_1ms":163,"lbm_write_time_us":30863,"lbm_writes_lt_1ms":143,"mutex_wait_us":37,"peak_mem_usage":13409612,"reinsert_count":0,"thread_start_us":278,"threads_started":5,"update_count":500}
I20260812 06:16:27.524278  7112 maintenance_manager.cc:419] P 980c963649d04baea69021b1b0a8384b: Scheduling UndoDeltaBlockGCOp(c16a6eddbf5045db853a30cd2752fdb7): 411733 bytes on disk
I20260812 06:16:27.524852  7026 maintenance_manager.cc:643] P 980c963649d04baea69021b1b0a8384b: UndoDeltaBlockGCOp(c16a6eddbf5045db853a30cd2752fdb7) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":47,"lbm_reads_lt_1ms":4}
I20260812 06:16:27.525290  7112 maintenance_manager.cc:419] P 980c963649d04baea69021b1b0a8384b: Scheduling FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7): perf score=6.157687
I20260812 06:16:27.546468  7026 maintenance_manager.cc:643] P 980c963649d04baea69021b1b0a8384b: FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7) complete. Timing: real 0.021s	user 0.009s	sys 0.011s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":9595,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":202,"reinsert_count":0,"update_count":1000}
I20260812 06:16:27.546861  7112 maintenance_manager.cc:419] P 980c963649d04baea69021b1b0a8384b: Scheduling FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7): perf score=2.188937
I20260812 06:16:27.556895  7026 maintenance_manager.cc:643] P 980c963649d04baea69021b1b0a8384b: FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7) complete. Timing: real 0.010s	user 0.000s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3243,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:27.557696  7112 maintenance_manager.cc:419] P 980c963649d04baea69021b1b0a8384b: Scheduling MajorDeltaCompactionOp(c16a6eddbf5045db853a30cd2752fdb7): perf score=1.000000
I20260812 06:16:27.656543  7026 maintenance_manager.cc:643] P 980c963649d04baea69021b1b0a8384b: MajorDeltaCompactionOp(c16a6eddbf5045db853a30cd2752fdb7) complete. Timing: real 0.099s	user 0.062s	sys 0.033s Metrics: {"cfile_cache_miss":322,"cfile_cache_miss_bytes":16036716,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":667,"lbm_read_time_us":5807,"lbm_reads_lt_1ms":362,"lbm_write_time_us":16369,"lbm_writes_lt_1ms":333,"mutex_wait_us":2,"peak_mem_usage":36812022,"reinsert_count":0,"spinlock_wait_cycles":5760,"update_count":1450}
I20260812 06:16:27.657069  7112 maintenance_manager.cc:419] P 980c963649d04baea69021b1b0a8384b: Scheduling FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7): perf score=7.149875
I20260812 06:16:27.683765  7026 maintenance_manager.cc:643] P 980c963649d04baea69021b1b0a8384b: FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7) complete. Timing: real 0.027s	user 0.024s	sys 0.000s Metrics: {"bytes_written":8943515,"delete_count":0,"lbm_write_time_us":11619,"lbm_writes_lt_1ms":221,"reinsert_count":0,"update_count":1090}
I20260812 06:16:27.684226  7112 maintenance_manager.cc:419] P 980c963649d04baea69021b1b0a8384b: Scheduling FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7): perf score=2.188937
I20260812 06:16:27.695035  7026 maintenance_manager.cc:643] P 980c963649d04baea69021b1b0a8384b: FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3364205,"delete_count":0,"lbm_write_time_us":3799,"lbm_writes_lt_1ms":85,"reinsert_count":0,"update_count":410}
I20260812 06:16:27.695633  7112 maintenance_manager.cc:419] P 980c963649d04baea69021b1b0a8384b: Scheduling MajorDeltaCompactionOp(c16a6eddbf5045db853a30cd2752fdb7): perf score=1.000000
I20260812 06:16:27.814491  7026 maintenance_manager.cc:643] P 980c963649d04baea69021b1b0a8384b: MajorDeltaCompactionOp(c16a6eddbf5045db853a30cd2752fdb7) complete. Timing: real 0.119s	user 0.071s	sys 0.043s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16446953,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":753,"lbm_read_time_us":9150,"lbm_reads_lt_1ms":364,"lbm_write_time_us":19999,"lbm_writes_lt_1ms":343,"mutex_wait_us":44,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":9344,"update_count":1500}
I20260812 06:16:27.815012  7112 maintenance_manager.cc:419] P 980c963649d04baea69021b1b0a8384b: Scheduling FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7): perf score=10.126437
I20260812 06:16:27.856628  7026 maintenance_manager.cc:643] P 980c963649d04baea69021b1b0a8384b: FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7) complete. Timing: real 0.041s	user 0.014s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14150,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:27.857144  7112 maintenance_manager.cc:419] P 980c963649d04baea69021b1b0a8384b: Scheduling FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7): perf score=2.188937
I20260812 06:16:27.867290  7026 maintenance_manager.cc:643] P 980c963649d04baea69021b1b0a8384b: FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3833,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:27.867815  7112 maintenance_manager.cc:419] P 980c963649d04baea69021b1b0a8384b: Scheduling MajorDeltaCompactionOp(c16a6eddbf5045db853a30cd2752fdb7): perf score=1.000000
I20260812 06:16:27.987324  7026 maintenance_manager.cc:643] P 980c963649d04baea69021b1b0a8384b: MajorDeltaCompactionOp(c16a6eddbf5045db853a30cd2752fdb7) complete. Timing: real 0.119s	user 0.107s	sys 0.012s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20549381,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":190,"lbm_read_time_us":7588,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24334,"lbm_writes_lt_1ms":443,"mutex_wait_us":26,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":13312,"update_count":2000}
I20260812 06:16:27.987838  7112 maintenance_manager.cc:419] P 980c963649d04baea69021b1b0a8384b: Scheduling FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7): perf score=10.126437
I20260812 06:16:28.025507  7026 maintenance_manager.cc:643] P 980c963649d04baea69021b1b0a8384b: FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7) complete. Timing: real 0.038s	user 0.024s	sys 0.012s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":16292,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:28.026031  7112 maintenance_manager.cc:419] P 980c963649d04baea69021b1b0a8384b: Scheduling FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7): perf score=2.188937
I20260812 06:16:28.035799  7026 maintenance_manager.cc:643] P 980c963649d04baea69021b1b0a8384b: FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3774,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:28.036260  7112 maintenance_manager.cc:419] P 980c963649d04baea69021b1b0a8384b: Scheduling MajorDeltaCompactionOp(c16a6eddbf5045db853a30cd2752fdb7): perf score=1.000000
I20260812 06:16:28.154856  7026 maintenance_manager.cc:643] P 980c963649d04baea69021b1b0a8384b: MajorDeltaCompactionOp(c16a6eddbf5045db853a30cd2752fdb7) complete. Timing: real 0.118s	user 0.092s	sys 0.026s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20549384,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":207,"lbm_read_time_us":8763,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23323,"lbm_writes_lt_1ms":443,"mutex_wait_us":22,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7552,"update_count":2000}
I20260812 06:16:28.155306  7112 maintenance_manager.cc:419] P 980c963649d04baea69021b1b0a8384b: Scheduling FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7): perf score=10.126437
I20260812 06:16:28.194219  7026 maintenance_manager.cc:643] P 980c963649d04baea69021b1b0a8384b: FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7) complete. Timing: real 0.039s	user 0.032s	sys 0.006s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14365,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:28.194756  7112 maintenance_manager.cc:419] P 980c963649d04baea69021b1b0a8384b: Scheduling FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7): perf score=2.188937
I20260812 06:16:28.204546  7026 maintenance_manager.cc:643] P 980c963649d04baea69021b1b0a8384b: FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3773,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:28.205013  7112 maintenance_manager.cc:419] P 980c963649d04baea69021b1b0a8384b: Scheduling MajorDeltaCompactionOp(c16a6eddbf5045db853a30cd2752fdb7): perf score=1.000000
I20260812 06:16:28.349924  7026 maintenance_manager.cc:643] P 980c963649d04baea69021b1b0a8384b: MajorDeltaCompactionOp(c16a6eddbf5045db853a30cd2752fdb7) complete. Timing: real 0.145s	user 0.097s	sys 0.043s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20549382,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":673,"lbm_read_time_us":9243,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24552,"lbm_writes_lt_1ms":443,"mutex_wait_us":232,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6912,"update_count":2000}
I20260812 06:16:28.350479  7112 maintenance_manager.cc:419] P 980c963649d04baea69021b1b0a8384b: Scheduling FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7): perf score=10.126437
I20260812 06:16:28.391179  7026 maintenance_manager.cc:643] P 980c963649d04baea69021b1b0a8384b: FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7) complete. Timing: real 0.041s	user 0.014s	sys 0.016s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14491,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:28.391628  7112 maintenance_manager.cc:419] P 980c963649d04baea69021b1b0a8384b: Scheduling FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7): perf score=2.188937
I20260812 06:16:28.401309  7026 maintenance_manager.cc:643] P 980c963649d04baea69021b1b0a8384b: FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3749,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:28.402025  7112 maintenance_manager.cc:419] P 980c963649d04baea69021b1b0a8384b: Scheduling MajorDeltaCompactionOp(c16a6eddbf5045db853a30cd2752fdb7): perf score=1.000000
I20260812 06:16:28.524431  7026 maintenance_manager.cc:643] P 980c963649d04baea69021b1b0a8384b: MajorDeltaCompactionOp(c16a6eddbf5045db853a30cd2752fdb7) complete. Timing: real 0.122s	user 0.087s	sys 0.034s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20549382,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1538,"lbm_read_time_us":8137,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25542,"lbm_writes_lt_1ms":443,"mutex_wait_us":253,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6656,"update_count":2000}
I20260812 06:16:28.525024  7112 maintenance_manager.cc:419] P 980c963649d04baea69021b1b0a8384b: Scheduling FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7): perf score=10.126437
I20260812 06:16:28.562917  7026 maintenance_manager.cc:643] P 980c963649d04baea69021b1b0a8384b: FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7) complete. Timing: real 0.038s	user 0.012s	sys 0.021s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15410,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:28.563449  7112 maintenance_manager.cc:419] P 980c963649d04baea69021b1b0a8384b: Scheduling FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7): perf score=2.188937
I20260812 06:16:28.578023  7026 maintenance_manager.cc:643] P 980c963649d04baea69021b1b0a8384b: FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7) complete. Timing: real 0.014s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5321,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:28.578469  7112 maintenance_manager.cc:419] P 980c963649d04baea69021b1b0a8384b: Scheduling MajorDeltaCompactionOp(c16a6eddbf5045db853a30cd2752fdb7): perf score=1.000000
I20260812 06:16:28.690935  7026 maintenance_manager.cc:643] P 980c963649d04baea69021b1b0a8384b: MajorDeltaCompactionOp(c16a6eddbf5045db853a30cd2752fdb7) complete. Timing: real 0.112s	user 0.080s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20549383,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":183,"lbm_read_time_us":7610,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24384,"lbm_writes_lt_1ms":443,"mutex_wait_us":42,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":13440,"update_count":2000}
I20260812 06:16:28.691387  7112 maintenance_manager.cc:419] P 980c963649d04baea69021b1b0a8384b: Scheduling FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7): perf score=10.126437
I20260812 06:16:28.734402  7026 maintenance_manager.cc:643] P 980c963649d04baea69021b1b0a8384b: FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7) complete. Timing: real 0.043s	user 0.023s	sys 0.015s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":14060,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:28.734891  7112 maintenance_manager.cc:419] P 980c963649d04baea69021b1b0a8384b: Scheduling FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7): perf score=2.188937
I20260812 06:16:28.744748  7026 maintenance_manager.cc:643] P 980c963649d04baea69021b1b0a8384b: FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3820,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:28.745157  7112 maintenance_manager.cc:419] P 980c963649d04baea69021b1b0a8384b: Scheduling FlushMRSOp(c16a6eddbf5045db853a30cd2752fdb7): perf score=1.000000
I20260812 06:16:28.785542  7026 maintenance_manager.cc:643] P 980c963649d04baea69021b1b0a8384b: FlushMRSOp(c16a6eddbf5045db853a30cd2752fdb7) complete. Timing: real 0.040s	user 0.026s	sys 0.004s Metrics: {"bytes_written":1234474,"cfile_init":1,"dirs.queue_time_us":36,"dirs.run_cpu_time_us":213,"dirs.run_wall_time_us":1391,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1436,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:16:28.786306  7112 maintenance_manager.cc:419] P 980c963649d04baea69021b1b0a8384b: Scheduling LogGCOp(c16a6eddbf5045db853a30cd2752fdb7): free 129279359 bytes of WAL
I20260812 06:16:28.786577  7026 log_reader.cc:385] T c16a6eddbf5045db853a30cd2752fdb7: removed 13 log segments from log reader
I20260812 06:16:28.786635  7026 log.cc:1079] T c16a6eddbf5045db853a30cd2752fdb7 P 980c963649d04baea69021b1b0a8384b: Deleting log segment in path: /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386886772-6856-0/minicluster-data/ts-0-root/wals/c16a6eddbf5045db853a30cd2752fdb7/wal-000000001 (ops 1-6)
I20260812 06:16:28.786677  7026 log.cc:1079] T c16a6eddbf5045db853a30cd2752fdb7 P 980c963649d04baea69021b1b0a8384b: Deleting log segment in path: /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386886772-6856-0/minicluster-data/ts-0-root/wals/c16a6eddbf5045db853a30cd2752fdb7/wal-000000002 (ops 7-11)
I20260812 06:16:28.786711  7026 log.cc:1079] T c16a6eddbf5045db853a30cd2752fdb7 P 980c963649d04baea69021b1b0a8384b: Deleting log segment in path: /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386886772-6856-0/minicluster-data/ts-0-root/wals/c16a6eddbf5045db853a30cd2752fdb7/wal-000000003 (ops 12-16)
I20260812 06:16:28.786736  7026 log.cc:1079] T c16a6eddbf5045db853a30cd2752fdb7 P 980c963649d04baea69021b1b0a8384b: Deleting log segment in path: /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386886772-6856-0/minicluster-data/ts-0-root/wals/c16a6eddbf5045db853a30cd2752fdb7/wal-000000004 (ops 17-20)
I20260812 06:16:28.786767  7026 log.cc:1079] T c16a6eddbf5045db853a30cd2752fdb7 P 980c963649d04baea69021b1b0a8384b: Deleting log segment in path: /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386886772-6856-0/minicluster-data/ts-0-root/wals/c16a6eddbf5045db853a30cd2752fdb7/wal-000000005 (ops 21-25)
I20260812 06:16:28.786798  7026 log.cc:1079] T c16a6eddbf5045db853a30cd2752fdb7 P 980c963649d04baea69021b1b0a8384b: Deleting log segment in path: /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386886772-6856-0/minicluster-data/ts-0-root/wals/c16a6eddbf5045db853a30cd2752fdb7/wal-000000006 (ops 26-30)
I20260812 06:16:28.786830  7026 log.cc:1079] T c16a6eddbf5045db853a30cd2752fdb7 P 980c963649d04baea69021b1b0a8384b: Deleting log segment in path: /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386886772-6856-0/minicluster-data/ts-0-root/wals/c16a6eddbf5045db853a30cd2752fdb7/wal-000000007 (ops 31-35)
I20260812 06:16:28.786860  7026 log.cc:1079] T c16a6eddbf5045db853a30cd2752fdb7 P 980c963649d04baea69021b1b0a8384b: Deleting log segment in path: /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386886772-6856-0/minicluster-data/ts-0-root/wals/c16a6eddbf5045db853a30cd2752fdb7/wal-000000008 (ops 36-40)
I20260812 06:16:28.786892  7026 log.cc:1079] T c16a6eddbf5045db853a30cd2752fdb7 P 980c963649d04baea69021b1b0a8384b: Deleting log segment in path: /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386886772-6856-0/minicluster-data/ts-0-root/wals/c16a6eddbf5045db853a30cd2752fdb7/wal-000000009 (ops 41-44)
I20260812 06:16:28.786922  7026 log.cc:1079] T c16a6eddbf5045db853a30cd2752fdb7 P 980c963649d04baea69021b1b0a8384b: Deleting log segment in path: /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386886772-6856-0/minicluster-data/ts-0-root/wals/c16a6eddbf5045db853a30cd2752fdb7/wal-000000010 (ops 45-49)
I20260812 06:16:28.786955  7026 log.cc:1079] T c16a6eddbf5045db853a30cd2752fdb7 P 980c963649d04baea69021b1b0a8384b: Deleting log segment in path: /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386886772-6856-0/minicluster-data/ts-0-root/wals/c16a6eddbf5045db853a30cd2752fdb7/wal-000000011 (ops 50-54)
I20260812 06:16:28.786979  7026 log.cc:1079] T c16a6eddbf5045db853a30cd2752fdb7 P 980c963649d04baea69021b1b0a8384b: Deleting log segment in path: /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386886772-6856-0/minicluster-data/ts-0-root/wals/c16a6eddbf5045db853a30cd2752fdb7/wal-000000012 (ops 55-59)
I20260812 06:16:28.787011  7026 log.cc:1079] T c16a6eddbf5045db853a30cd2752fdb7 P 980c963649d04baea69021b1b0a8384b: Deleting log segment in path: /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386886772-6856-0/minicluster-data/ts-0-root/wals/c16a6eddbf5045db853a30cd2752fdb7/wal-000000013 (ops 60-64)
I20260812 06:16:28.808908  7026 maintenance_manager.cc:643] P 980c963649d04baea69021b1b0a8384b: LogGCOp(c16a6eddbf5045db853a30cd2752fdb7) complete. Timing: real 0.022s	user 0.000s	sys 0.019s Metrics: {}
I20260812 06:16:28.809250  7112 maintenance_manager.cc:419] P 980c963649d04baea69021b1b0a8384b: Scheduling FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7): perf score=3.181125
I20260812 06:16:28.824942  7026 maintenance_manager.cc:643] P 980c963649d04baea69021b1b0a8384b: FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7) complete. Timing: real 0.016s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":3940,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:16:28.825347  7112 maintenance_manager.cc:419] P 980c963649d04baea69021b1b0a8384b: Scheduling FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7): perf score=2.188937
I20260812 06:16:28.837566  7026 maintenance_manager.cc:643] P 980c963649d04baea69021b1b0a8384b: FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7) complete. Timing: real 0.012s	user 0.007s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4702,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:28.838013  7112 maintenance_manager.cc:419] P 980c963649d04baea69021b1b0a8384b: Scheduling UndoDeltaBlockGCOp(c16a6eddbf5045db853a30cd2752fdb7): 473 bytes on disk
I20260812 06:16:28.838389  7026 maintenance_manager.cc:643] P 980c963649d04baea69021b1b0a8384b: UndoDeltaBlockGCOp(c16a6eddbf5045db853a30cd2752fdb7) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":44,"lbm_reads_lt_1ms":4}
I20260812 06:16:28.838778  7112 maintenance_manager.cc:419] P 980c963649d04baea69021b1b0a8384b: Scheduling MajorDeltaCompactionOp(c16a6eddbf5045db853a30cd2752fdb7): perf score=1.000000
I20260812 06:16:29.021667  7026 maintenance_manager.cc:643] P 980c963649d04baea69021b1b0a8384b: MajorDeltaCompactionOp(c16a6eddbf5045db853a30cd2752fdb7) complete. Timing: real 0.183s	user 0.118s	sys 0.064s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28754437,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":889,"lbm_read_time_us":13267,"lbm_reads_lt_1ms":674,"lbm_write_time_us":28979,"lbm_writes_lt_1ms":643,"mutex_wait_us":260,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":5376,"thread_start_us":68,"threads_started":1,"update_count":3000}
I20260812 06:16:29.022189  7112 maintenance_manager.cc:419] P 980c963649d04baea69021b1b0a8384b: Scheduling FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7): perf score=14.095187
I20260812 06:16:29.080538  7026 maintenance_manager.cc:643] P 980c963649d04baea69021b1b0a8384b: FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7) complete. Timing: real 0.058s	user 0.030s	sys 0.017s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21964,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":401,"reinsert_count":0,"update_count":2000}
I20260812 06:16:29.081055  7112 maintenance_manager.cc:419] P 980c963649d04baea69021b1b0a8384b: Scheduling FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7): perf score=2.188937
I20260812 06:16:29.095907  7026 maintenance_manager.cc:643] P 980c963649d04baea69021b1b0a8384b: FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7) complete. Timing: real 0.015s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5511,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:29.096446  7112 maintenance_manager.cc:419] P 980c963649d04baea69021b1b0a8384b: Scheduling MajorDeltaCompactionOp(c16a6eddbf5045db853a30cd2752fdb7): perf score=1.000000
I20260812 06:16:29.247750  7026 maintenance_manager.cc:643] P 980c963649d04baea69021b1b0a8384b: MajorDeltaCompactionOp(c16a6eddbf5045db853a30cd2752fdb7) complete. Timing: real 0.151s	user 0.095s	sys 0.056s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24651793,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":912,"lbm_read_time_us":9898,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26285,"lbm_writes_lt_1ms":543,"mutex_wait_us":3,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:16:29.248342  7112 maintenance_manager.cc:419] P 980c963649d04baea69021b1b0a8384b: Scheduling FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7): perf score=14.095187
I20260812 06:16:29.300048  7026 maintenance_manager.cc:643] P 980c963649d04baea69021b1b0a8384b: FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7) complete. Timing: real 0.052s	user 0.033s	sys 0.009s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19002,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:29.300573  7112 maintenance_manager.cc:419] P 980c963649d04baea69021b1b0a8384b: Scheduling FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7): perf score=2.188937
I20260812 06:16:29.310686  7026 maintenance_manager.cc:643] P 980c963649d04baea69021b1b0a8384b: FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3799,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:29.311939  7112 maintenance_manager.cc:419] P 980c963649d04baea69021b1b0a8384b: Scheduling MajorDeltaCompactionOp(c16a6eddbf5045db853a30cd2752fdb7): perf score=1.000000
I20260812 06:16:29.474150  7026 maintenance_manager.cc:643] P 980c963649d04baea69021b1b0a8384b: MajorDeltaCompactionOp(c16a6eddbf5045db853a30cd2752fdb7) complete. Timing: real 0.162s	user 0.105s	sys 0.047s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24651793,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":240,"lbm_read_time_us":11145,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26856,"lbm_writes_lt_1ms":543,"mutex_wait_us":41,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":24832,"update_count":2500}
I20260812 06:16:29.474645  7112 maintenance_manager.cc:419] P 980c963649d04baea69021b1b0a8384b: Scheduling FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7): perf score=14.095187
I20260812 06:16:29.522480  7026 maintenance_manager.cc:643] P 980c963649d04baea69021b1b0a8384b: FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7) complete. Timing: real 0.048s	user 0.023s	sys 0.023s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":17611,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:29.522890  7112 maintenance_manager.cc:419] P 980c963649d04baea69021b1b0a8384b: Scheduling FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7): perf score=2.188937
I20260812 06:16:29.532830  7026 maintenance_manager.cc:643] P 980c963649d04baea69021b1b0a8384b: FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7) complete. Timing: real 0.010s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3873,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:29.533259  7112 maintenance_manager.cc:419] P 980c963649d04baea69021b1b0a8384b: Scheduling MajorDeltaCompactionOp(c16a6eddbf5045db853a30cd2752fdb7): perf score=1.000000
I20260812 06:16:29.708854  7026 maintenance_manager.cc:643] P 980c963649d04baea69021b1b0a8384b: MajorDeltaCompactionOp(c16a6eddbf5045db853a30cd2752fdb7) complete. Timing: real 0.175s	user 0.096s	sys 0.068s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24651794,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":120,"lbm_read_time_us":11047,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29873,"lbm_writes_lt_1ms":543,"mutex_wait_us":27,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2500}
I20260812 06:16:29.709337  7112 maintenance_manager.cc:419] P 980c963649d04baea69021b1b0a8384b: Scheduling FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7): perf score=14.095187
I20260812 06:16:29.756558  7026 maintenance_manager.cc:643] P 980c963649d04baea69021b1b0a8384b: FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7) complete. Timing: real 0.047s	user 0.021s	sys 0.013s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":16598,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:29.757095  7112 maintenance_manager.cc:419] P 980c963649d04baea69021b1b0a8384b: Scheduling FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7): perf score=2.188937
I20260812 06:16:29.774513  7026 maintenance_manager.cc:643] P 980c963649d04baea69021b1b0a8384b: FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7) complete. Timing: real 0.017s	user 0.008s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3729,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:29.775013  7112 maintenance_manager.cc:419] P 980c963649d04baea69021b1b0a8384b: Scheduling MajorDeltaCompactionOp(c16a6eddbf5045db853a30cd2752fdb7): perf score=1.000000
I20260812 06:16:29.937288  7026 maintenance_manager.cc:643] P 980c963649d04baea69021b1b0a8384b: MajorDeltaCompactionOp(c16a6eddbf5045db853a30cd2752fdb7) complete. Timing: real 0.162s	user 0.114s	sys 0.041s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24651795,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":96,"lbm_read_time_us":10640,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27013,"lbm_writes_lt_1ms":543,"mutex_wait_us":36,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9472,"update_count":2500}
I20260812 06:16:29.937975  7112 maintenance_manager.cc:419] P 980c963649d04baea69021b1b0a8384b: Scheduling FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7): perf score=14.095187
I20260812 06:16:29.989886  7026 maintenance_manager.cc:643] P 980c963649d04baea69021b1b0a8384b: FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7) complete. Timing: real 0.052s	user 0.022s	sys 0.028s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22786,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:29.990365  7112 maintenance_manager.cc:419] P 980c963649d04baea69021b1b0a8384b: Scheduling FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7): perf score=2.188937
I20260812 06:16:30.001565  7026 maintenance_manager.cc:643] P 980c963649d04baea69021b1b0a8384b: FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7) complete. Timing: real 0.011s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4156,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:30.001981  7112 maintenance_manager.cc:419] P 980c963649d04baea69021b1b0a8384b: Scheduling MajorDeltaCompactionOp(c16a6eddbf5045db853a30cd2752fdb7): perf score=1.000000
I20260812 06:16:30.173180  7026 maintenance_manager.cc:643] P 980c963649d04baea69021b1b0a8384b: MajorDeltaCompactionOp(c16a6eddbf5045db853a30cd2752fdb7) complete. Timing: real 0.171s	user 0.127s	sys 0.035s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24651794,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":558,"lbm_read_time_us":9319,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28994,"lbm_writes_lt_1ms":543,"mutex_wait_us":17,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4736,"update_count":2500}
I20260812 06:16:30.173748  7112 maintenance_manager.cc:419] P 980c963649d04baea69021b1b0a8384b: Scheduling FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7): perf score=14.095187
I20260812 06:16:30.224812  7026 maintenance_manager.cc:643] P 980c963649d04baea69021b1b0a8384b: FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7) complete. Timing: real 0.051s	user 0.023s	sys 0.023s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":22294,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:30.225349  7112 maintenance_manager.cc:419] P 980c963649d04baea69021b1b0a8384b: Scheduling FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7): perf score=2.188937
I20260812 06:16:30.246575  7026 maintenance_manager.cc:643] P 980c963649d04baea69021b1b0a8384b: FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7) complete. Timing: real 0.018s	user 0.007s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6122,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:30.247069  7112 maintenance_manager.cc:419] P 980c963649d04baea69021b1b0a8384b: Scheduling FlushMRSOp(c16a6eddbf5045db853a30cd2752fdb7): perf score=1.000000
I20260812 06:16:30.299901  7026 maintenance_manager.cc:643] P 980c963649d04baea69021b1b0a8384b: FlushMRSOp(c16a6eddbf5045db853a30cd2752fdb7) complete. Timing: real 0.053s	user 0.021s	sys 0.007s Metrics: {"bytes_written":1357580,"cfile_init":1,"dirs.queue_time_us":47,"dirs.run_cpu_time_us":186,"dirs.run_wall_time_us":1109,"drs_written":1,"lbm_read_time_us":43,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2658,"lbm_writes_lt_1ms":44,"peak_mem_usage":0,"rows_written":33,"spinlock_wait_cycles":1280}
I20260812 06:16:30.300637  7112 maintenance_manager.cc:419] P 980c963649d04baea69021b1b0a8384b: Scheduling FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7): perf score=3.181125
I20260812 06:16:30.318979  7026 maintenance_manager.cc:643] P 980c963649d04baea69021b1b0a8384b: FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7) complete. Timing: real 0.018s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4257,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:16:30.319414  7112 maintenance_manager.cc:419] P 980c963649d04baea69021b1b0a8384b: Scheduling LogGCOp(c16a6eddbf5045db853a30cd2752fdb7): free 136728229 bytes of WAL
I20260812 06:16:30.319617  7026 log_reader.cc:385] T c16a6eddbf5045db853a30cd2752fdb7: removed 13 log segments from log reader
I20260812 06:16:30.319659  7026 log.cc:1079] T c16a6eddbf5045db853a30cd2752fdb7 P 980c963649d04baea69021b1b0a8384b: Deleting log segment in path: /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386886772-6856-0/minicluster-data/ts-0-root/wals/c16a6eddbf5045db853a30cd2752fdb7/wal-000000014 (ops 65-69)
I20260812 06:16:30.319689  7026 log.cc:1079] T c16a6eddbf5045db853a30cd2752fdb7 P 980c963649d04baea69021b1b0a8384b: Deleting log segment in path: /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386886772-6856-0/minicluster-data/ts-0-root/wals/c16a6eddbf5045db853a30cd2752fdb7/wal-000000015 (ops 70-74)
I20260812 06:16:30.319720  7026 log.cc:1079] T c16a6eddbf5045db853a30cd2752fdb7 P 980c963649d04baea69021b1b0a8384b: Deleting log segment in path: /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386886772-6856-0/minicluster-data/ts-0-root/wals/c16a6eddbf5045db853a30cd2752fdb7/wal-000000016 (ops 75-79)
I20260812 06:16:30.319743  7026 log.cc:1079] T c16a6eddbf5045db853a30cd2752fdb7 P 980c963649d04baea69021b1b0a8384b: Deleting log segment in path: /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386886772-6856-0/minicluster-data/ts-0-root/wals/c16a6eddbf5045db853a30cd2752fdb7/wal-000000017 (ops 80-84)
I20260812 06:16:30.319775  7026 log.cc:1079] T c16a6eddbf5045db853a30cd2752fdb7 P 980c963649d04baea69021b1b0a8384b: Deleting log segment in path: /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386886772-6856-0/minicluster-data/ts-0-root/wals/c16a6eddbf5045db853a30cd2752fdb7/wal-000000018 (ops 85-89)
I20260812 06:16:30.319806  7026 log.cc:1079] T c16a6eddbf5045db853a30cd2752fdb7 P 980c963649d04baea69021b1b0a8384b: Deleting log segment in path: /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386886772-6856-0/minicluster-data/ts-0-root/wals/c16a6eddbf5045db853a30cd2752fdb7/wal-000000019 (ops 90-94)
I20260812 06:16:30.319839  7026 log.cc:1079] T c16a6eddbf5045db853a30cd2752fdb7 P 980c963649d04baea69021b1b0a8384b: Deleting log segment in path: /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386886772-6856-0/minicluster-data/ts-0-root/wals/c16a6eddbf5045db853a30cd2752fdb7/wal-000000020 (ops 95-99)
I20260812 06:16:30.319869  7026 log.cc:1079] T c16a6eddbf5045db853a30cd2752fdb7 P 980c963649d04baea69021b1b0a8384b: Deleting log segment in path: /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386886772-6856-0/minicluster-data/ts-0-root/wals/c16a6eddbf5045db853a30cd2752fdb7/wal-000000021 (ops 100-104)
I20260812 06:16:30.319900  7026 log.cc:1079] T c16a6eddbf5045db853a30cd2752fdb7 P 980c963649d04baea69021b1b0a8384b: Deleting log segment in path: /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386886772-6856-0/minicluster-data/ts-0-root/wals/c16a6eddbf5045db853a30cd2752fdb7/wal-000000022 (ops 105-109)
I20260812 06:16:30.319932  7026 log.cc:1079] T c16a6eddbf5045db853a30cd2752fdb7 P 980c963649d04baea69021b1b0a8384b: Deleting log segment in path: /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386886772-6856-0/minicluster-data/ts-0-root/wals/c16a6eddbf5045db853a30cd2752fdb7/wal-000000023 (ops 110-114)
I20260812 06:16:30.319963  7026 log.cc:1079] T c16a6eddbf5045db853a30cd2752fdb7 P 980c963649d04baea69021b1b0a8384b: Deleting log segment in path: /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386886772-6856-0/minicluster-data/ts-0-root/wals/c16a6eddbf5045db853a30cd2752fdb7/wal-000000024 (ops 115-119)
I20260812 06:16:30.319994  7026 log.cc:1079] T c16a6eddbf5045db853a30cd2752fdb7 P 980c963649d04baea69021b1b0a8384b: Deleting log segment in path: /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386886772-6856-0/minicluster-data/ts-0-root/wals/c16a6eddbf5045db853a30cd2752fdb7/wal-000000025 (ops 120-124)
I20260812 06:16:30.320034  7026 log.cc:1079] T c16a6eddbf5045db853a30cd2752fdb7 P 980c963649d04baea69021b1b0a8384b: Deleting log segment in path: /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386886772-6856-0/minicluster-data/ts-0-root/wals/c16a6eddbf5045db853a30cd2752fdb7/wal-000000026 (ops 125-129)
I20260812 06:16:30.341688  7026 maintenance_manager.cc:643] P 980c963649d04baea69021b1b0a8384b: LogGCOp(c16a6eddbf5045db853a30cd2752fdb7) complete. Timing: real 0.022s	user 0.000s	sys 0.022s Metrics: {}
I20260812 06:16:30.342034  7112 maintenance_manager.cc:419] P 980c963649d04baea69021b1b0a8384b: Scheduling UndoDeltaBlockGCOp(c16a6eddbf5045db853a30cd2752fdb7): 506 bytes on disk
I20260812 06:16:30.342401  7026 maintenance_manager.cc:643] P 980c963649d04baea69021b1b0a8384b: UndoDeltaBlockGCOp(c16a6eddbf5045db853a30cd2752fdb7) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":47,"lbm_reads_lt_1ms":4}
I20260812 06:16:30.343384  7112 maintenance_manager.cc:419] P 980c963649d04baea69021b1b0a8384b: Scheduling FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7): perf score=2.188937
I20260812 06:16:30.360814  7026 maintenance_manager.cc:643] P 980c963649d04baea69021b1b0a8384b: FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7) complete. Timing: real 0.017s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3730,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:30.361275  7112 maintenance_manager.cc:419] P 980c963649d04baea69021b1b0a8384b: Scheduling FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7): perf score=2.188937
I20260812 06:16:30.370200  7026 maintenance_manager.cc:643] P 980c963649d04baea69021b1b0a8384b: FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7) complete. Timing: real 0.009s	user 0.007s	sys 0.001s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3245,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:30.370570  7112 maintenance_manager.cc:419] P 980c963649d04baea69021b1b0a8384b: Scheduling MajorDeltaCompactionOp(c16a6eddbf5045db853a30cd2752fdb7): perf score=1.000000
I20260812 06:16:30.620013  7026 maintenance_manager.cc:643] P 980c963649d04baea69021b1b0a8384b: MajorDeltaCompactionOp(c16a6eddbf5045db853a30cd2752fdb7) complete. Timing: real 0.249s	user 0.161s	sys 0.077s Metrics: {"cfile_cache_miss":835,"cfile_cache_miss_bytes":36959375,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":425,"lbm_read_time_us":18921,"lbm_reads_lt_1ms":875,"lbm_write_time_us":41735,"lbm_writes_lt_1ms":843,"mutex_wait_us":18,"peak_mem_usage":100395616,"reinsert_count":0,"spinlock_wait_cycles":11392,"thread_start_us":64,"threads_started":1,"update_count":4000}
I20260812 06:16:30.620471  7112 maintenance_manager.cc:419] P 980c963649d04baea69021b1b0a8384b: Scheduling FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7): perf score=18.063937
I20260812 06:16:30.675523  7026 maintenance_manager.cc:643] P 980c963649d04baea69021b1b0a8384b: FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7) complete. Timing: real 0.055s	user 0.035s	sys 0.016s Metrics: {"bytes_written":20512316,"delete_count":0,"lbm_write_time_us":24349,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:16:30.675974  7112 maintenance_manager.cc:419] P 980c963649d04baea69021b1b0a8384b: Scheduling FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7): perf score=2.188937
I20260812 06:16:30.690320  7026 maintenance_manager.cc:643] P 980c963649d04baea69021b1b0a8384b: FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7) complete. Timing: real 0.014s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5438,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:30.690882  7112 maintenance_manager.cc:419] P 980c963649d04baea69021b1b0a8384b: Scheduling MajorDeltaCompactionOp(c16a6eddbf5045db853a30cd2752fdb7): perf score=1.000000
I20260812 06:16:30.873131  7026 maintenance_manager.cc:643] P 980c963649d04baea69021b1b0a8384b: MajorDeltaCompactionOp(c16a6eddbf5045db853a30cd2752fdb7) complete. Timing: real 0.182s	user 0.126s	sys 0.056s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28754208,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":74,"lbm_read_time_us":14388,"lbm_reads_lt_1ms":672,"lbm_write_time_us":33264,"lbm_writes_lt_1ms":643,"mutex_wait_us":19,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":10624,"update_count":3000}
I20260812 06:16:30.873656  7112 maintenance_manager.cc:419] P 980c963649d04baea69021b1b0a8384b: Scheduling FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7): perf score=14.095187
I20260812 06:16:30.918537  7026 maintenance_manager.cc:643] P 980c963649d04baea69021b1b0a8384b: FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7) complete. Timing: real 0.045s	user 0.035s	sys 0.009s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20344,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:30.919030  7112 maintenance_manager.cc:419] P 980c963649d04baea69021b1b0a8384b: Scheduling FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7): perf score=2.188937
I20260812 06:16:30.933104  7026 maintenance_manager.cc:643] P 980c963649d04baea69021b1b0a8384b: FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5774,"lbm_writes_lt_1ms":103,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":500}
I20260812 06:16:30.933534  7112 maintenance_manager.cc:419] P 980c963649d04baea69021b1b0a8384b: Scheduling MajorDeltaCompactionOp(c16a6eddbf5045db853a30cd2752fdb7): perf score=1.000000
I20260812 06:16:31.082533  7026 maintenance_manager.cc:643] P 980c963649d04baea69021b1b0a8384b: MajorDeltaCompactionOp(c16a6eddbf5045db853a30cd2752fdb7) complete. Timing: real 0.149s	user 0.101s	sys 0.045s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24651795,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":113,"lbm_read_time_us":9594,"lbm_reads_lt_1ms":564,"lbm_write_time_us":27187,"lbm_writes_lt_1ms":543,"mutex_wait_us":17,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6272,"update_count":2500}
I20260812 06:16:31.083108  7112 maintenance_manager.cc:419] P 980c963649d04baea69021b1b0a8384b: Scheduling FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7): perf score=14.095187
I20260812 06:16:31.136479  7026 maintenance_manager.cc:643] P 980c963649d04baea69021b1b0a8384b: FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7) complete. Timing: real 0.053s	user 0.009s	sys 0.032s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20361,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:31.136963  7112 maintenance_manager.cc:419] P 980c963649d04baea69021b1b0a8384b: Scheduling FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7): perf score=2.188937
I20260812 06:16:31.147071  7026 maintenance_manager.cc:643] P 980c963649d04baea69021b1b0a8384b: FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3606,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:31.147614  7112 maintenance_manager.cc:419] P 980c963649d04baea69021b1b0a8384b: Scheduling MajorDeltaCompactionOp(c16a6eddbf5045db853a30cd2752fdb7): perf score=1.000000
I20260812 06:16:31.318004  7026 maintenance_manager.cc:643] P 980c963649d04baea69021b1b0a8384b: MajorDeltaCompactionOp(c16a6eddbf5045db853a30cd2752fdb7) complete. Timing: real 0.170s	user 0.133s	sys 0.032s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24651793,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1162,"lbm_read_time_us":12320,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28251,"lbm_writes_lt_1ms":543,"mutex_wait_us":40,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12672,"update_count":2500}
I20260812 06:16:31.318532  7112 maintenance_manager.cc:419] P 980c963649d04baea69021b1b0a8384b: Scheduling FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7): perf score=14.095187
I20260812 06:16:31.425864  7026 maintenance_manager.cc:643] P 980c963649d04baea69021b1b0a8384b: FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7) complete. Timing: real 0.107s	user 0.024s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18101,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:31.426455  7112 maintenance_manager.cc:419] P 980c963649d04baea69021b1b0a8384b: Scheduling FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7): perf score=6.157687
I20260812 06:16:31.525121  7026 maintenance_manager.cc:643] P 980c963649d04baea69021b1b0a8384b: FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7) complete. Timing: real 0.098s	user 0.015s	sys 0.005s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":9119,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:16:31.525609  7112 maintenance_manager.cc:419] P 980c963649d04baea69021b1b0a8384b: Scheduling FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7): perf score=10.126437
W20260812 06:16:31.621536  7141 log.cc:927] Time spent T c16a6eddbf5045db853a30cd2752fdb7 P 980c963649d04baea69021b1b0a8384b: Append to log took a long time: real 0.082s	user 0.000s	sys 0.001s
I20260812 06:16:31.654754  7026 maintenance_manager.cc:643] P 980c963649d04baea69021b1b0a8384b: FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7) complete. Timing: real 0.129s	user 0.016s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":109519,"lbm_writes_10-100_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:16:31.655253  7112 maintenance_manager.cc:419] P 980c963649d04baea69021b1b0a8384b: Scheduling FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7): perf score=2.188937
I20260812 06:16:31.664891  7026 maintenance_manager.cc:643] P 980c963649d04baea69021b1b0a8384b: FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3639,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:31.665407  7112 maintenance_manager.cc:419] P 980c963649d04baea69021b1b0a8384b: Scheduling FlushMRSOp(c16a6eddbf5045db853a30cd2752fdb7): perf score=1.000000
I20260812 06:16:31.691170  7026 maintenance_manager.cc:643] P 980c963649d04baea69021b1b0a8384b: FlushMRSOp(c16a6eddbf5045db853a30cd2752fdb7) complete. Timing: real 0.026s	user 0.024s	sys 0.000s Metrics: {"bytes_written":1152510,"cfile_init":1,"dirs.queue_time_us":49,"dirs.run_cpu_time_us":196,"dirs.run_wall_time_us":1051,"drs_written":1,"lbm_read_time_us":36,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1495,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:16:31.691896  7112 maintenance_manager.cc:419] P 980c963649d04baea69021b1b0a8384b: Scheduling LogGCOp(c16a6eddbf5045db853a30cd2752fdb7): free 112239554 bytes of WAL
I20260812 06:16:31.692123  7026 log_reader.cc:385] T c16a6eddbf5045db853a30cd2752fdb7: removed 11 log segments from log reader
I20260812 06:16:31.692171  7026 log.cc:1079] T c16a6eddbf5045db853a30cd2752fdb7 P 980c963649d04baea69021b1b0a8384b: Deleting log segment in path: /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386886772-6856-0/minicluster-data/ts-0-root/wals/c16a6eddbf5045db853a30cd2752fdb7/wal-000000027 (ops 130-134)
I20260812 06:16:31.692209  7026 log.cc:1079] T c16a6eddbf5045db853a30cd2752fdb7 P 980c963649d04baea69021b1b0a8384b: Deleting log segment in path: /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386886772-6856-0/minicluster-data/ts-0-root/wals/c16a6eddbf5045db853a30cd2752fdb7/wal-000000028 (ops 135-138)
I20260812 06:16:31.692241  7026 log.cc:1079] T c16a6eddbf5045db853a30cd2752fdb7 P 980c963649d04baea69021b1b0a8384b: Deleting log segment in path: /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386886772-6856-0/minicluster-data/ts-0-root/wals/c16a6eddbf5045db853a30cd2752fdb7/wal-000000029 (ops 139-143)
I20260812 06:16:31.692274  7026 log.cc:1079] T c16a6eddbf5045db853a30cd2752fdb7 P 980c963649d04baea69021b1b0a8384b: Deleting log segment in path: /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386886772-6856-0/minicluster-data/ts-0-root/wals/c16a6eddbf5045db853a30cd2752fdb7/wal-000000030 (ops 144-148)
I20260812 06:16:31.692305  7026 log.cc:1079] T c16a6eddbf5045db853a30cd2752fdb7 P 980c963649d04baea69021b1b0a8384b: Deleting log segment in path: /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386886772-6856-0/minicluster-data/ts-0-root/wals/c16a6eddbf5045db853a30cd2752fdb7/wal-000000031 (ops 149-153)
I20260812 06:16:31.692337  7026 log.cc:1079] T c16a6eddbf5045db853a30cd2752fdb7 P 980c963649d04baea69021b1b0a8384b: Deleting log segment in path: /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386886772-6856-0/minicluster-data/ts-0-root/wals/c16a6eddbf5045db853a30cd2752fdb7/wal-000000032 (ops 154-158)
I20260812 06:16:31.692389  7026 log.cc:1079] T c16a6eddbf5045db853a30cd2752fdb7 P 980c963649d04baea69021b1b0a8384b: Deleting log segment in path: /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386886772-6856-0/minicluster-data/ts-0-root/wals/c16a6eddbf5045db853a30cd2752fdb7/wal-000000033 (ops 159-163)
I20260812 06:16:31.692444  7026 log.cc:1079] T c16a6eddbf5045db853a30cd2752fdb7 P 980c963649d04baea69021b1b0a8384b: Deleting log segment in path: /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386886772-6856-0/minicluster-data/ts-0-root/wals/c16a6eddbf5045db853a30cd2752fdb7/wal-000000034 (ops 164-168)
I20260812 06:16:31.692474  7026 log.cc:1079] T c16a6eddbf5045db853a30cd2752fdb7 P 980c963649d04baea69021b1b0a8384b: Deleting log segment in path: /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386886772-6856-0/minicluster-data/ts-0-root/wals/c16a6eddbf5045db853a30cd2752fdb7/wal-000000035 (ops 169-173)
I20260812 06:16:31.692498  7026 log.cc:1079] T c16a6eddbf5045db853a30cd2752fdb7 P 980c963649d04baea69021b1b0a8384b: Deleting log segment in path: /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386886772-6856-0/minicluster-data/ts-0-root/wals/c16a6eddbf5045db853a30cd2752fdb7/wal-000000036 (ops 174-178)
I20260812 06:16:31.692529  7026 log.cc:1079] T c16a6eddbf5045db853a30cd2752fdb7 P 980c963649d04baea69021b1b0a8384b: Deleting log segment in path: /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515386886772-6856-0/minicluster-data/ts-0-root/wals/c16a6eddbf5045db853a30cd2752fdb7/wal-000000037 (ops 179-183)
I20260812 06:16:31.711905  7026 maintenance_manager.cc:643] P 980c963649d04baea69021b1b0a8384b: LogGCOp(c16a6eddbf5045db853a30cd2752fdb7) complete. Timing: real 0.020s	user 0.000s	sys 0.017s Metrics: {}
I20260812 06:16:31.712388  7112 maintenance_manager.cc:419] P 980c963649d04baea69021b1b0a8384b: Scheduling UndoDeltaBlockGCOp(c16a6eddbf5045db853a30cd2752fdb7): 447 bytes on disk
I20260812 06:16:31.712807  7026 maintenance_manager.cc:643] P 980c963649d04baea69021b1b0a8384b: UndoDeltaBlockGCOp(c16a6eddbf5045db853a30cd2752fdb7) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":49,"lbm_reads_lt_1ms":4}
I20260812 06:16:31.713462  7112 maintenance_manager.cc:419] P 980c963649d04baea69021b1b0a8384b: Scheduling FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7): perf score=3.181125
I20260812 06:16:31.733534  7026 maintenance_manager.cc:643] P 980c963649d04baea69021b1b0a8384b: FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7) complete. Timing: real 0.020s	user 0.012s	sys 0.005s Metrics: {"bytes_written":4512902,"delete_count":0,"lbm_write_time_us":6660,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:16:31.733932  7112 maintenance_manager.cc:419] P 980c963649d04baea69021b1b0a8384b: Scheduling FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7): perf score=2.188937
I20260812 06:16:31.742545  7026 maintenance_manager.cc:643] P 980c963649d04baea69021b1b0a8384b: FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7) complete. Timing: real 0.008s	user 0.007s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3283,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:31.742988  7112 maintenance_manager.cc:419] P 980c963649d04baea69021b1b0a8384b: Scheduling MajorDeltaCompactionOp(c16a6eddbf5045db853a30cd2752fdb7): perf score=1.000000
I20260812 06:16:32.029219  6856 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.762s	user 1.629s	sys 0.136s
I20260812 06:16:32.059288  7026 maintenance_manager.cc:643] P 980c963649d04baea69021b1b0a8384b: MajorDeltaCompactionOp(c16a6eddbf5045db853a30cd2752fdb7) complete. Timing: real 0.316s	user 0.232s	sys 0.083s Metrics: {"cfile_cache_miss":1236,"cfile_cache_miss_bytes":53369144,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":6,"delta_iterators_relevant":6,"lbm_read_time_us":23068,"lbm_reads_lt_1ms":1272,"lbm_write_time_us":59981,"lbm_writes_lt_1ms":1243,"peak_mem_usage":150101904,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":6000}
I20260812 06:16:32.059808  7112 maintenance_manager.cc:419] P 980c963649d04baea69021b1b0a8384b: Scheduling FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7): perf score=22.032687
I20260812 06:16:32.106318  7026 maintenance_manager.cc:643] P 980c963649d04baea69021b1b0a8384b: FlushDeltaMemStoresOp(c16a6eddbf5045db853a30cd2752fdb7) complete. Timing: real 0.046s	user 0.033s	sys 0.013s Metrics: {"bytes_written":24614722,"delete_count":0,"lbm_write_time_us":22520,"lbm_writes_lt_1ms":603,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":3000}
I20260812 06:16:32.106755  7112 maintenance_manager.cc:419] P 980c963649d04baea69021b1b0a8384b: Scheduling MajorDeltaCompactionOp(c16a6eddbf5045db853a30cd2752fdb7): perf score=1.000000
I20260812 06:16:32.181547  6856 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.152s	user 0.005s	sys 0.000s
I20260812 06:16:32.182282  6856 tablet_server.cc:179] TabletServer@127.6.178.1:0 shutting down...
I20260812 06:16:32.264559  7026 maintenance_manager.cc:643] P 980c963649d04baea69021b1b0a8384b: MajorDeltaCompactionOp(c16a6eddbf5045db853a30cd2752fdb7) complete. Timing: real 0.158s	user 0.099s	sys 0.058s Metrics: {"cfile_cache_miss":631,"cfile_cache_miss_bytes":28754083,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":465,"lbm_read_time_us":12345,"lbm_reads_lt_1ms":667,"lbm_write_time_us":30738,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":642,"mutex_wait_us":101,"peak_mem_usage":75542472,"reinsert_count":0,"update_count":3000}
I20260812 06:16:32.265316  6856 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:16:32.265745  6856 tablet_replica.cc:333] T c16a6eddbf5045db853a30cd2752fdb7 P 980c963649d04baea69021b1b0a8384b: stopping tablet replica
I20260812 06:16:32.265965  6856 raft_consensus.cc:2243] T c16a6eddbf5045db853a30cd2752fdb7 P 980c963649d04baea69021b1b0a8384b [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:32.266175  6856 raft_consensus.cc:2272] T c16a6eddbf5045db853a30cd2752fdb7 P 980c963649d04baea69021b1b0a8384b [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:32.280406  6856 tablet_server.cc:196] TabletServer@127.6.178.1:0 shutdown complete.
I20260812 06:16:32.415171  6856 master.cc:562] Master@127.6.178.62:38079 shutting down...
I20260812 06:16:32.418586  6856 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 39efb4aaeb49450d8b3ebe58cad89e5a [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:32.418743  6856 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 39efb4aaeb49450d8b3ebe58cad89e5a [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:32.418798  6856 tablet_replica.cc:333] T 00000000000000000000000000000000 P 39efb4aaeb49450d8b3ebe58cad89e5a: stopping tablet replica
I20260812 06:16:32.430734  6856 master.cc:584] Master@127.6.178.62:38079 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5606 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:16:32.513365  6856 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.6.178.62:34073
I20260812 06:16:32.514287  6856 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:32.516072  7168 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:16:32.516155  6856 server_base.cc:1061] running on GCE node
W20260812 06:16:32.516085  7167 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:16:32.516275  7170 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:16:32.516453  6856 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:32.516495  6856 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:16:32.516510  6856 hybrid_clock.cc:648] HybridClock initialized: now 1786515392516510 us; error 0 us; skew 500 ppm
I20260812 06:16:32.517221  6856 webserver.cc:533] Webserver started at http://127.6.178.62:35503/ using document root <none> and password file <none>
I20260812 06:16:32.517341  6856 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:32.517381  6856 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:32.517467  6856 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:32.517814  6856 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386886772-6856-0/minicluster-data/master-0-root/instance:
uuid: "e647c60dce764322811cca21850c941f"
format_stamp: "Formatted at 2026-08-12 06:16:32 on dist-test-slave-42z9"
I20260812 06:16:32.519183  6856 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:16:32.520058  7181 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:32.520255  6856 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:16:32.520316  6856 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386886772-6856-0/minicluster-data/master-0-root
uuid: "e647c60dce764322811cca21850c941f"
format_stamp: "Formatted at 2026-08-12 06:16:32 on dist-test-slave-42z9"
I20260812 06:16:32.520370  6856 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386886772-6856-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386886772-6856-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386886772-6856-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:16:32.551421  6856 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:32.551767  6856 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:32.555639  6856 rpc_server.cc:307] RPC server started. Bound to: 127.6.178.62:34073
I20260812 06:16:32.562422  7258 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.6.178.62:34073 every 8 connection(s)
I20260812 06:16:32.562847  7260 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:16:32.564558  7260 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P e647c60dce764322811cca21850c941f: Bootstrap starting.
I20260812 06:16:32.565306  7260 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P e647c60dce764322811cca21850c941f: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:32.566324  7260 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P e647c60dce764322811cca21850c941f: No bootstrap required, opened a new log
I20260812 06:16:32.566681  7260 raft_consensus.cc:359] T 00000000000000000000000000000000 P e647c60dce764322811cca21850c941f [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e647c60dce764322811cca21850c941f" member_type: VOTER }
I20260812 06:16:32.566767  7260 raft_consensus.cc:385] T 00000000000000000000000000000000 P e647c60dce764322811cca21850c941f [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:32.566798  7260 raft_consensus.cc:740] T 00000000000000000000000000000000 P e647c60dce764322811cca21850c941f [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: e647c60dce764322811cca21850c941f, State: Initialized, Role: FOLLOWER
I20260812 06:16:32.566931  7260 consensus_queue.cc:260] T 00000000000000000000000000000000 P e647c60dce764322811cca21850c941f [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: "e647c60dce764322811cca21850c941f" member_type: VOTER }
I20260812 06:16:32.567025  7260 raft_consensus.cc:399] T 00000000000000000000000000000000 P e647c60dce764322811cca21850c941f [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:32.567066  7260 raft_consensus.cc:493] T 00000000000000000000000000000000 P e647c60dce764322811cca21850c941f [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:32.567113  7260 raft_consensus.cc:3060] T 00000000000000000000000000000000 P e647c60dce764322811cca21850c941f [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:32.567751  7260 raft_consensus.cc:515] T 00000000000000000000000000000000 P e647c60dce764322811cca21850c941f [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e647c60dce764322811cca21850c941f" member_type: VOTER }
I20260812 06:16:32.567874  7260 leader_election.cc:304] T 00000000000000000000000000000000 P e647c60dce764322811cca21850c941f [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: e647c60dce764322811cca21850c941f; no voters: 
I20260812 06:16:32.568043  7260 leader_election.cc:290] T 00000000000000000000000000000000 P e647c60dce764322811cca21850c941f [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:32.568145  7266 raft_consensus.cc:2804] T 00000000000000000000000000000000 P e647c60dce764322811cca21850c941f [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:32.568322  7266 raft_consensus.cc:697] T 00000000000000000000000000000000 P e647c60dce764322811cca21850c941f [term 1 LEADER]: Becoming Leader. State: Replica: e647c60dce764322811cca21850c941f, State: Running, Role: LEADER
I20260812 06:16:32.568424  7260 sys_catalog.cc:565] T 00000000000000000000000000000000 P e647c60dce764322811cca21850c941f [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:16:32.568450  7266 consensus_queue.cc:237] T 00000000000000000000000000000000 P e647c60dce764322811cca21850c941f [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: "e647c60dce764322811cca21850c941f" member_type: VOTER }
I20260812 06:16:32.568846  7267 sys_catalog.cc:455] T 00000000000000000000000000000000 P e647c60dce764322811cca21850c941f [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "e647c60dce764322811cca21850c941f" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e647c60dce764322811cca21850c941f" member_type: VOTER } }
I20260812 06:16:32.568946  7267 sys_catalog.cc:458] T 00000000000000000000000000000000 P e647c60dce764322811cca21850c941f [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:32.568863  7268 sys_catalog.cc:455] T 00000000000000000000000000000000 P e647c60dce764322811cca21850c941f [sys.catalog]: SysCatalogTable state changed. Reason: New leader e647c60dce764322811cca21850c941f. Latest consensus state: current_term: 1 leader_uuid: "e647c60dce764322811cca21850c941f" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "e647c60dce764322811cca21850c941f" member_type: VOTER } }
I20260812 06:16:32.569203  7271 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:16:32.569554  7268 sys_catalog.cc:458] T 00000000000000000000000000000000 P e647c60dce764322811cca21850c941f [sys.catalog]: This master's current role is: LEADER
I20260812 06:16:32.570230  7271 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:16:32.570374  6856 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:16:32.571867  7271 catalog_manager.cc:1383] Generated new cluster ID: e34058a187b34658a87e00af8eed95f1
I20260812 06:16:32.571916  7271 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:16:32.592833  7271 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:16:32.593323  7271 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:16:32.597608  7271 catalog_manager.cc:6092] T 00000000000000000000000000000000 P e647c60dce764322811cca21850c941f: Generated new TSK 0
I20260812 06:16:32.597743  7271 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:16:32.602394  6856 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:16:32.604064  7296 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:16:32.604131  6856 server_base.cc:1061] running on GCE node
W20260812 06:16:32.604141  7299 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:16:32.604075  7295 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:16:32.604409  6856 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:16:32.604451  6856 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:16:32.604494  6856 hybrid_clock.cc:648] HybridClock initialized: now 1786515392604493 us; error 0 us; skew 500 ppm
I20260812 06:16:32.605232  6856 webserver.cc:533] Webserver started at http://127.6.178.1:40645/ using document root <none> and password file <none>
I20260812 06:16:32.605370  6856 fs_manager.cc:362] Metadata directory not provided
I20260812 06:16:32.605419  6856 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:16:32.605542  6856 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:16:32.605881  6856 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386886772-6856-0/minicluster-data/ts-0-root/instance:
uuid: "7f80eb985fab48c08bfb6d219c7b7418"
format_stamp: "Formatted at 2026-08-12 06:16:32 on dist-test-slave-42z9"
I20260812 06:16:32.607200  6856 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:16:32.608036  7305 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:32.608253  6856 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:16:32.608318  6856 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386886772-6856-0/minicluster-data/ts-0-root
uuid: "7f80eb985fab48c08bfb6d219c7b7418"
format_stamp: "Formatted at 2026-08-12 06:16:32 on dist-test-slave-42z9"
I20260812 06:16:32.608381  6856 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386886772-6856-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386886772-6856-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386886772-6856-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:16:32.618590  6856 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:16:32.618877  6856 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:16:32.619118  6856 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:16:32.619524  6856 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:16:32.619560  6856 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:32.619599  6856 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:16:32.619627  6856 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:16:32.623443  6856 rpc_server.cc:307] RPC server started. Bound to: 127.6.178.1:37153
I20260812 06:16:32.623466  7399 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.6.178.1:37153 every 8 connection(s)
I20260812 06:16:32.631670  7400 heartbeater.cc:344] Connected to a master server at 127.6.178.62:34073
I20260812 06:16:32.631762  7400 heartbeater.cc:461] Registering TS with master...
I20260812 06:16:32.631942  7400 heartbeater.cc:507] Master 127.6.178.62:34073 requested a full tablet report, sending...
I20260812 06:16:32.632485  7207 ts_manager.cc:194] Registered new tserver with Master: 7f80eb985fab48c08bfb6d219c7b7418 (127.6.178.1:37153)
I20260812 06:16:32.632617  6856 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.008809046s
I20260812 06:16:32.633242  7207 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:44404
I20260812 06:16:32.638996  7207 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:44416:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:16:32.646661  7346 tablet_service.cc:1511] Processing CreateTablet for tablet ca04d86e833d4b898cb28ec8dd64196c (DEFAULT_TABLE table=heavy-update-compaction-test [id=be67c8bcd59b44e9a41bbdf1bcd7f11b]), partition=
I20260812 06:16:32.646903  7346 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet ca04d86e833d4b898cb28ec8dd64196c. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:16:32.648629  7420 tablet_bootstrap.cc:492] T ca04d86e833d4b898cb28ec8dd64196c P 7f80eb985fab48c08bfb6d219c7b7418: Bootstrap starting.
I20260812 06:16:32.649477  7420 tablet_bootstrap.cc:654] T ca04d86e833d4b898cb28ec8dd64196c P 7f80eb985fab48c08bfb6d219c7b7418: Neither blocks nor log segments found. Creating new log.
I20260812 06:16:32.650372  7420 tablet_bootstrap.cc:492] T ca04d86e833d4b898cb28ec8dd64196c P 7f80eb985fab48c08bfb6d219c7b7418: No bootstrap required, opened a new log
I20260812 06:16:32.650455  7420 ts_tablet_manager.cc:1403] T ca04d86e833d4b898cb28ec8dd64196c P 7f80eb985fab48c08bfb6d219c7b7418: Time spent bootstrapping tablet: real 0.002s	user 0.000s	sys 0.001s
I20260812 06:16:32.650794  7420 raft_consensus.cc:359] T ca04d86e833d4b898cb28ec8dd64196c P 7f80eb985fab48c08bfb6d219c7b7418 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7f80eb985fab48c08bfb6d219c7b7418" member_type: VOTER last_known_addr { host: "127.6.178.1" port: 37153 } }
I20260812 06:16:32.650878  7420 raft_consensus.cc:385] T ca04d86e833d4b898cb28ec8dd64196c P 7f80eb985fab48c08bfb6d219c7b7418 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:16:32.650908  7420 raft_consensus.cc:740] T ca04d86e833d4b898cb28ec8dd64196c P 7f80eb985fab48c08bfb6d219c7b7418 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 7f80eb985fab48c08bfb6d219c7b7418, State: Initialized, Role: FOLLOWER
I20260812 06:16:32.651027  7420 consensus_queue.cc:260] T ca04d86e833d4b898cb28ec8dd64196c P 7f80eb985fab48c08bfb6d219c7b7418 [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: "7f80eb985fab48c08bfb6d219c7b7418" member_type: VOTER last_known_addr { host: "127.6.178.1" port: 37153 } }
I20260812 06:16:32.651103  7420 raft_consensus.cc:399] T ca04d86e833d4b898cb28ec8dd64196c P 7f80eb985fab48c08bfb6d219c7b7418 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:16:32.651136  7420 raft_consensus.cc:493] T ca04d86e833d4b898cb28ec8dd64196c P 7f80eb985fab48c08bfb6d219c7b7418 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:16:32.651183  7420 raft_consensus.cc:3060] T ca04d86e833d4b898cb28ec8dd64196c P 7f80eb985fab48c08bfb6d219c7b7418 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:16:32.651865  7420 raft_consensus.cc:515] T ca04d86e833d4b898cb28ec8dd64196c P 7f80eb985fab48c08bfb6d219c7b7418 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7f80eb985fab48c08bfb6d219c7b7418" member_type: VOTER last_known_addr { host: "127.6.178.1" port: 37153 } }
I20260812 06:16:32.651990  7420 leader_election.cc:304] T ca04d86e833d4b898cb28ec8dd64196c P 7f80eb985fab48c08bfb6d219c7b7418 [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: 7f80eb985fab48c08bfb6d219c7b7418; no voters: 
I20260812 06:16:32.652189  7420 leader_election.cc:290] T ca04d86e833d4b898cb28ec8dd64196c P 7f80eb985fab48c08bfb6d219c7b7418 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:16:32.652293  7423 raft_consensus.cc:2804] T ca04d86e833d4b898cb28ec8dd64196c P 7f80eb985fab48c08bfb6d219c7b7418 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:16:32.652491  7420 ts_tablet_manager.cc:1434] T ca04d86e833d4b898cb28ec8dd64196c P 7f80eb985fab48c08bfb6d219c7b7418: Time spent starting tablet: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:16:32.652518  7400 heartbeater.cc:499] Master 127.6.178.62:34073 was elected leader, sending a full tablet report...
I20260812 06:16:32.652537  7423 raft_consensus.cc:697] T ca04d86e833d4b898cb28ec8dd64196c P 7f80eb985fab48c08bfb6d219c7b7418 [term 1 LEADER]: Becoming Leader. State: Replica: 7f80eb985fab48c08bfb6d219c7b7418, State: Running, Role: LEADER
I20260812 06:16:32.652704  7423 consensus_queue.cc:237] T ca04d86e833d4b898cb28ec8dd64196c P 7f80eb985fab48c08bfb6d219c7b7418 [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: "7f80eb985fab48c08bfb6d219c7b7418" member_type: VOTER last_known_addr { host: "127.6.178.1" port: 37153 } }
I20260812 06:16:32.653891  7207 catalog_manager.cc:5719] T ca04d86e833d4b898cb28ec8dd64196c P 7f80eb985fab48c08bfb6d219c7b7418 reported cstate change: term changed from 0 to 1, leader changed from <none> to 7f80eb985fab48c08bfb6d219c7b7418 (127.6.178.1). New cstate: current_term: 1 leader_uuid: "7f80eb985fab48c08bfb6d219c7b7418" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "7f80eb985fab48c08bfb6d219c7b7418" member_type: VOTER last_known_addr { host: "127.6.178.1" port: 37153 } health_report { overall_health: HEALTHY } } }
I20260812 06:16:32.705936  6856 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.048s	user 0.019s	sys 0.002s
I20260812 06:16:32.874339  7401 maintenance_manager.cc:419] P 7f80eb985fab48c08bfb6d219c7b7418: Scheduling FlushMRSOp(ca04d86e833d4b898cb28ec8dd64196c): perf score=23.023690
I20260812 06:16:33.027460  7313 maintenance_manager.cc:643] P 7f80eb985fab48c08bfb6d219c7b7418: FlushMRSOp(ca04d86e833d4b898cb28ec8dd64196c) complete. Timing: real 0.153s	user 0.119s	sys 0.032s Metrics: {"bytes_written":13004907,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":60,"dirs.run_cpu_time_us":239,"dirs.run_wall_time_us":770,"drs_written":1,"lbm_read_time_us":40,"lbm_reads_lt_1ms":4,"lbm_write_time_us":40290,"lbm_writes_lt_1ms":874,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"update_count":1585}
I20260812 06:16:33.028158  7401 maintenance_manager.cc:419] P 7f80eb985fab48c08bfb6d219c7b7418: Scheduling LogGCOp(ca04d86e833d4b898cb28ec8dd64196c): free 20743880 bytes of WAL
I20260812 06:16:33.028389  7313 log_reader.cc:385] T ca04d86e833d4b898cb28ec8dd64196c: removed 2 log segments from log reader
I20260812 06:16:33.028450  7313 log.cc:1079] T ca04d86e833d4b898cb28ec8dd64196c P 7f80eb985fab48c08bfb6d219c7b7418: Deleting log segment in path: /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386886772-6856-0/minicluster-data/ts-0-root/wals/ca04d86e833d4b898cb28ec8dd64196c/wal-000000001 (ops 1-6)
I20260812 06:16:33.028549  7313 log.cc:1079] T ca04d86e833d4b898cb28ec8dd64196c P 7f80eb985fab48c08bfb6d219c7b7418: Deleting log segment in path: /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386886772-6856-0/minicluster-data/ts-0-root/wals/ca04d86e833d4b898cb28ec8dd64196c/wal-000000002 (ops 7-11)
I20260812 06:16:33.033532  7313 maintenance_manager.cc:643] P 7f80eb985fab48c08bfb6d219c7b7418: LogGCOp(ca04d86e833d4b898cb28ec8dd64196c) complete. Timing: real 0.005s	user 0.000s	sys 0.005s Metrics: {}
I20260812 06:16:33.033828  7401 maintenance_manager.cc:419] P 7f80eb985fab48c08bfb6d219c7b7418: Scheduling UndoDeltaBlockGCOp(ca04d86e833d4b898cb28ec8dd64196c): 20513815 bytes on disk
I20260812 06:16:33.034171  7313 maintenance_manager.cc:643] P 7f80eb985fab48c08bfb6d219c7b7418: UndoDeltaBlockGCOp(ca04d86e833d4b898cb28ec8dd64196c) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4}
I20260812 06:16:33.034538  7401 maintenance_manager.cc:419] P 7f80eb985fab48c08bfb6d219c7b7418: Scheduling FlushDeltaMemStoresOp(ca04d86e833d4b898cb28ec8dd64196c): perf score=2.188937
I20260812 06:16:33.046329  7313 maintenance_manager.cc:643] P 7f80eb985fab48c08bfb6d219c7b7418: FlushDeltaMemStoresOp(ca04d86e833d4b898cb28ec8dd64196c) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":3815486,"delete_count":0,"lbm_write_time_us":3295,"lbm_writes_lt_1ms":96,"reinsert_count":0,"update_count":465}
I20260812 06:16:33.046753  7401 maintenance_manager.cc:419] P 7f80eb985fab48c08bfb6d219c7b7418: Scheduling MajorDeltaCompactionOp(ca04d86e833d4b898cb28ec8dd64196c): perf score=1.000000
I20260812 06:16:33.198066  7313 maintenance_manager.cc:643] P 7f80eb985fab48c08bfb6d219c7b7418: MajorDeltaCompactionOp(ca04d86e833d4b898cb28ec8dd64196c) complete. Timing: real 0.151s	user 0.088s	sys 0.053s Metrics: {"cfile_cache_miss":442,"cfile_cache_miss_bytes":21123516,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":429,"lbm_read_time_us":9252,"lbm_reads_lt_1ms":470,"lbm_write_time_us":23407,"lbm_writes_lt_1ms":453,"peak_mem_usage":51099678,"reinsert_count":0,"spinlock_wait_cycles":3712,"thread_start_us":285,"threads_started":5,"update_count":2050}
I20260812 06:16:33.198661  7401 maintenance_manager.cc:419] P 7f80eb985fab48c08bfb6d219c7b7418: Scheduling FlushDeltaMemStoresOp(ca04d86e833d4b898cb28ec8dd64196c): perf score=14.095187
I20260812 06:16:33.246227  7313 maintenance_manager.cc:643] P 7f80eb985fab48c08bfb6d219c7b7418: FlushDeltaMemStoresOp(ca04d86e833d4b898cb28ec8dd64196c) complete. Timing: real 0.047s	user 0.034s	sys 0.008s Metrics: {"bytes_written":15999660,"delete_count":0,"lbm_write_time_us":18819,"lbm_writes_lt_1ms":393,"reinsert_count":0,"update_count":1950}
I20260812 06:16:33.246731  7401 maintenance_manager.cc:419] P 7f80eb985fab48c08bfb6d219c7b7418: Scheduling MajorDeltaCompactionOp(ca04d86e833d4b898cb28ec8dd64196c): perf score=1.000000
I20260812 06:16:33.393910  7313 maintenance_manager.cc:643] P 7f80eb985fab48c08bfb6d219c7b7418: MajorDeltaCompactionOp(ca04d86e833d4b898cb28ec8dd64196c) complete. Timing: real 0.147s	user 0.110s	sys 0.032s Metrics: {"cfile_cache_miss":421,"cfile_cache_miss_bytes":20302911,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":163,"lbm_read_time_us":9242,"lbm_reads_lt_1ms":453,"lbm_write_time_us":23147,"lbm_writes_lt_1ms":433,"mutex_wait_us":67,"peak_mem_usage":49238594,"reinsert_count":0,"update_count":1950}
I20260812 06:16:33.394413  7401 maintenance_manager.cc:419] P 7f80eb985fab48c08bfb6d219c7b7418: Scheduling FlushDeltaMemStoresOp(ca04d86e833d4b898cb28ec8dd64196c): perf score=14.095187
I20260812 06:16:33.445569  7313 maintenance_manager.cc:643] P 7f80eb985fab48c08bfb6d219c7b7418: FlushDeltaMemStoresOp(ca04d86e833d4b898cb28ec8dd64196c) complete. Timing: real 0.051s	user 0.034s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22092,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:33.446089  7401 maintenance_manager.cc:419] P 7f80eb985fab48c08bfb6d219c7b7418: Scheduling FlushDeltaMemStoresOp(ca04d86e833d4b898cb28ec8dd64196c): perf score=2.188937
I20260812 06:16:33.455650  7313 maintenance_manager.cc:643] P 7f80eb985fab48c08bfb6d219c7b7418: FlushDeltaMemStoresOp(ca04d86e833d4b898cb28ec8dd64196c) complete. Timing: real 0.009s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3663,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:33.456241  7401 maintenance_manager.cc:419] P 7f80eb985fab48c08bfb6d219c7b7418: Scheduling MajorDeltaCompactionOp(ca04d86e833d4b898cb28ec8dd64196c): perf score=1.000000
I20260812 06:16:33.630717  7313 maintenance_manager.cc:643] P 7f80eb985fab48c08bfb6d219c7b7418: MajorDeltaCompactionOp(ca04d86e833d4b898cb28ec8dd64196c) complete. Timing: real 0.174s	user 0.089s	sys 0.076s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":243,"lbm_read_time_us":10606,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28756,"lbm_writes_lt_1ms":543,"mutex_wait_us":20,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":17664,"update_count":2500}
I20260812 06:16:33.631189  7401 maintenance_manager.cc:419] P 7f80eb985fab48c08bfb6d219c7b7418: Scheduling FlushDeltaMemStoresOp(ca04d86e833d4b898cb28ec8dd64196c): perf score=14.095187
I20260812 06:16:33.673597  7313 maintenance_manager.cc:643] P 7f80eb985fab48c08bfb6d219c7b7418: FlushDeltaMemStoresOp(ca04d86e833d4b898cb28ec8dd64196c) complete. Timing: real 0.042s	user 0.022s	sys 0.017s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":16567,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:33.674134  7401 maintenance_manager.cc:419] P 7f80eb985fab48c08bfb6d219c7b7418: Scheduling FlushDeltaMemStoresOp(ca04d86e833d4b898cb28ec8dd64196c): perf score=2.188937
I20260812 06:16:33.683846  7313 maintenance_manager.cc:643] P 7f80eb985fab48c08bfb6d219c7b7418: FlushDeltaMemStoresOp(ca04d86e833d4b898cb28ec8dd64196c) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3766,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:33.684437  7401 maintenance_manager.cc:419] P 7f80eb985fab48c08bfb6d219c7b7418: Scheduling MajorDeltaCompactionOp(ca04d86e833d4b898cb28ec8dd64196c): perf score=1.000000
I20260812 06:16:33.830102  7313 maintenance_manager.cc:643] P 7f80eb985fab48c08bfb6d219c7b7418: MajorDeltaCompactionOp(ca04d86e833d4b898cb28ec8dd64196c) complete. Timing: real 0.145s	user 0.109s	sys 0.032s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":776,"lbm_read_time_us":8474,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29012,"lbm_writes_lt_1ms":543,"mutex_wait_us":39,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":4352,"update_count":2500}
I20260812 06:16:33.830715  7401 maintenance_manager.cc:419] P 7f80eb985fab48c08bfb6d219c7b7418: Scheduling FlushDeltaMemStoresOp(ca04d86e833d4b898cb28ec8dd64196c): perf score=11.118625
I20260812 06:16:33.867810  7313 maintenance_manager.cc:643] P 7f80eb985fab48c08bfb6d219c7b7418: FlushDeltaMemStoresOp(ca04d86e833d4b898cb28ec8dd64196c) complete. Timing: real 0.037s	user 0.026s	sys 0.008s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":15569,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:16:33.868407  7401 maintenance_manager.cc:419] P 7f80eb985fab48c08bfb6d219c7b7418: Scheduling FlushDeltaMemStoresOp(ca04d86e833d4b898cb28ec8dd64196c): perf score=2.188937
I20260812 06:16:33.886858  7313 maintenance_manager.cc:643] P 7f80eb985fab48c08bfb6d219c7b7418: FlushDeltaMemStoresOp(ca04d86e833d4b898cb28ec8dd64196c) complete. Timing: real 0.018s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4337,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:33.887298  7401 maintenance_manager.cc:419] P 7f80eb985fab48c08bfb6d219c7b7418: Scheduling FlushDeltaMemStoresOp(ca04d86e833d4b898cb28ec8dd64196c): perf score=2.188937
I20260812 06:16:33.895731  7313 maintenance_manager.cc:643] P 7f80eb985fab48c08bfb6d219c7b7418: FlushDeltaMemStoresOp(ca04d86e833d4b898cb28ec8dd64196c) complete. Timing: real 0.008s	user 0.007s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3092,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:33.896100  7401 maintenance_manager.cc:419] P 7f80eb985fab48c08bfb6d219c7b7418: Scheduling MajorDeltaCompactionOp(ca04d86e833d4b898cb28ec8dd64196c): perf score=1.000000
I20260812 06:16:34.032593  7313 maintenance_manager.cc:643] P 7f80eb985fab48c08bfb6d219c7b7418: MajorDeltaCompactionOp(ca04d86e833d4b898cb28ec8dd64196c) complete. Timing: real 0.136s	user 0.128s	sys 0.007s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815794,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1115,"lbm_read_time_us":8411,"lbm_reads_lt_1ms":573,"lbm_write_time_us":28896,"lbm_writes_lt_1ms":543,"mutex_wait_us":412,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11648,"update_count":2500}
I20260812 06:16:34.033265  7401 maintenance_manager.cc:419] P 7f80eb985fab48c08bfb6d219c7b7418: Scheduling FlushDeltaMemStoresOp(ca04d86e833d4b898cb28ec8dd64196c): perf score=10.126437
I20260812 06:16:34.062397  7313 maintenance_manager.cc:643] P 7f80eb985fab48c08bfb6d219c7b7418: FlushDeltaMemStoresOp(ca04d86e833d4b898cb28ec8dd64196c) complete. Timing: real 0.029s	user 0.016s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":12284,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:16:34.062860  7401 maintenance_manager.cc:419] P 7f80eb985fab48c08bfb6d219c7b7418: Scheduling FlushDeltaMemStoresOp(ca04d86e833d4b898cb28ec8dd64196c): perf score=2.188937
I20260812 06:16:34.078909  7313 maintenance_manager.cc:643] P 7f80eb985fab48c08bfb6d219c7b7418: FlushDeltaMemStoresOp(ca04d86e833d4b898cb28ec8dd64196c) complete. Timing: real 0.016s	user 0.001s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5846,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:34.079408  7401 maintenance_manager.cc:419] P 7f80eb985fab48c08bfb6d219c7b7418: Scheduling FlushMRSOp(ca04d86e833d4b898cb28ec8dd64196c): perf score=1.000000
I20260812 06:16:34.115141  7313 maintenance_manager.cc:643] P 7f80eb985fab48c08bfb6d219c7b7418: FlushMRSOp(ca04d86e833d4b898cb28ec8dd64196c) complete. Timing: real 0.036s	user 0.020s	sys 0.004s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":67,"dirs.run_cpu_time_us":202,"dirs.run_wall_time_us":1163,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1685,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:16:34.115831  7401 maintenance_manager.cc:419] P 7f80eb985fab48c08bfb6d219c7b7418: Scheduling UndoDeltaBlockGCOp(ca04d86e833d4b898cb28ec8dd64196c): 447 bytes on disk
I20260812 06:16:34.116217  7313 maintenance_manager.cc:643] P 7f80eb985fab48c08bfb6d219c7b7418: UndoDeltaBlockGCOp(ca04d86e833d4b898cb28ec8dd64196c) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":45,"lbm_reads_lt_1ms":4}
I20260812 06:16:34.116729  7401 maintenance_manager.cc:419] P 7f80eb985fab48c08bfb6d219c7b7418: Scheduling FlushDeltaMemStoresOp(ca04d86e833d4b898cb28ec8dd64196c): perf score=3.181125
I20260812 06:16:34.128580  7313 maintenance_manager.cc:643] P 7f80eb985fab48c08bfb6d219c7b7418: FlushDeltaMemStoresOp(ca04d86e833d4b898cb28ec8dd64196c) complete. Timing: real 0.012s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4512902,"delete_count":0,"lbm_write_time_us":3925,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:16:34.128998  7401 maintenance_manager.cc:419] P 7f80eb985fab48c08bfb6d219c7b7418: Scheduling LogGCOp(ca04d86e833d4b898cb28ec8dd64196c): free 112239316 bytes of WAL
I20260812 06:16:34.129212  7313 log_reader.cc:385] T ca04d86e833d4b898cb28ec8dd64196c: removed 11 log segments from log reader
I20260812 06:16:34.129258  7313 log.cc:1079] T ca04d86e833d4b898cb28ec8dd64196c P 7f80eb985fab48c08bfb6d219c7b7418: Deleting log segment in path: /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386886772-6856-0/minicluster-data/ts-0-root/wals/ca04d86e833d4b898cb28ec8dd64196c/wal-000000003 (ops 12-16)
I20260812 06:16:34.129297  7313 log.cc:1079] T ca04d86e833d4b898cb28ec8dd64196c P 7f80eb985fab48c08bfb6d219c7b7418: Deleting log segment in path: /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386886772-6856-0/minicluster-data/ts-0-root/wals/ca04d86e833d4b898cb28ec8dd64196c/wal-000000004 (ops 17-20)
I20260812 06:16:34.129328  7313 log.cc:1079] T ca04d86e833d4b898cb28ec8dd64196c P 7f80eb985fab48c08bfb6d219c7b7418: Deleting log segment in path: /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386886772-6856-0/minicluster-data/ts-0-root/wals/ca04d86e833d4b898cb28ec8dd64196c/wal-000000005 (ops 21-25)
I20260812 06:16:34.129359  7313 log.cc:1079] T ca04d86e833d4b898cb28ec8dd64196c P 7f80eb985fab48c08bfb6d219c7b7418: Deleting log segment in path: /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386886772-6856-0/minicluster-data/ts-0-root/wals/ca04d86e833d4b898cb28ec8dd64196c/wal-000000006 (ops 26-30)
I20260812 06:16:34.129390  7313 log.cc:1079] T ca04d86e833d4b898cb28ec8dd64196c P 7f80eb985fab48c08bfb6d219c7b7418: Deleting log segment in path: /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386886772-6856-0/minicluster-data/ts-0-root/wals/ca04d86e833d4b898cb28ec8dd64196c/wal-000000007 (ops 31-35)
I20260812 06:16:34.129420  7313 log.cc:1079] T ca04d86e833d4b898cb28ec8dd64196c P 7f80eb985fab48c08bfb6d219c7b7418: Deleting log segment in path: /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386886772-6856-0/minicluster-data/ts-0-root/wals/ca04d86e833d4b898cb28ec8dd64196c/wal-000000008 (ops 36-40)
I20260812 06:16:34.129472  7313 log.cc:1079] T ca04d86e833d4b898cb28ec8dd64196c P 7f80eb985fab48c08bfb6d219c7b7418: Deleting log segment in path: /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386886772-6856-0/minicluster-data/ts-0-root/wals/ca04d86e833d4b898cb28ec8dd64196c/wal-000000009 (ops 41-45)
I20260812 06:16:34.129509  7313 log.cc:1079] T ca04d86e833d4b898cb28ec8dd64196c P 7f80eb985fab48c08bfb6d219c7b7418: Deleting log segment in path: /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386886772-6856-0/minicluster-data/ts-0-root/wals/ca04d86e833d4b898cb28ec8dd64196c/wal-000000010 (ops 46-50)
I20260812 06:16:34.129541  7313 log.cc:1079] T ca04d86e833d4b898cb28ec8dd64196c P 7f80eb985fab48c08bfb6d219c7b7418: Deleting log segment in path: /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386886772-6856-0/minicluster-data/ts-0-root/wals/ca04d86e833d4b898cb28ec8dd64196c/wal-000000011 (ops 51-55)
I20260812 06:16:34.129570  7313 log.cc:1079] T ca04d86e833d4b898cb28ec8dd64196c P 7f80eb985fab48c08bfb6d219c7b7418: Deleting log segment in path: /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386886772-6856-0/minicluster-data/ts-0-root/wals/ca04d86e833d4b898cb28ec8dd64196c/wal-000000012 (ops 56-60)
I20260812 06:16:34.129601  7313 log.cc:1079] T ca04d86e833d4b898cb28ec8dd64196c P 7f80eb985fab48c08bfb6d219c7b7418: Deleting log segment in path: /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386886772-6856-0/minicluster-data/ts-0-root/wals/ca04d86e833d4b898cb28ec8dd64196c/wal-000000013 (ops 61-65)
I20260812 06:16:34.147557  7313 maintenance_manager.cc:643] P 7f80eb985fab48c08bfb6d219c7b7418: LogGCOp(ca04d86e833d4b898cb28ec8dd64196c) complete. Timing: real 0.018s	user 0.002s	sys 0.015s Metrics: {}
I20260812 06:16:34.147954  7401 maintenance_manager.cc:419] P 7f80eb985fab48c08bfb6d219c7b7418: Scheduling FlushDeltaMemStoresOp(ca04d86e833d4b898cb28ec8dd64196c): perf score=2.188937
I20260812 06:16:34.168247  7313 maintenance_manager.cc:643] P 7f80eb985fab48c08bfb6d219c7b7418: FlushDeltaMemStoresOp(ca04d86e833d4b898cb28ec8dd64196c) complete. Timing: real 0.020s	user 0.006s	sys 0.003s Metrics: {"bytes_written":3856509,"delete_count":0,"lbm_write_time_us":4372,"lbm_writes_lt_1ms":97,"reinsert_count":0,"update_count":470}
I20260812 06:16:34.168690  7401 maintenance_manager.cc:419] P 7f80eb985fab48c08bfb6d219c7b7418: Scheduling FlushDeltaMemStoresOp(ca04d86e833d4b898cb28ec8dd64196c): perf score=2.188937
I20260812 06:16:34.178100  7313 maintenance_manager.cc:643] P 7f80eb985fab48c08bfb6d219c7b7418: FlushDeltaMemStoresOp(ca04d86e833d4b898cb28ec8dd64196c) complete. Timing: real 0.009s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3938559,"delete_count":0,"lbm_write_time_us":3532,"lbm_writes_lt_1ms":99,"reinsert_count":0,"update_count":480}
I20260812 06:16:34.178490  7401 maintenance_manager.cc:419] P 7f80eb985fab48c08bfb6d219c7b7418: Scheduling MajorDeltaCompactionOp(ca04d86e833d4b898cb28ec8dd64196c): perf score=1.000000
I20260812 06:16:34.403338  7313 maintenance_manager.cc:643] P 7f80eb985fab48c08bfb6d219c7b7418: MajorDeltaCompactionOp(ca04d86e833d4b898cb28ec8dd64196c) complete. Timing: real 0.225s	user 0.144s	sys 0.070s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":33020858,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":176,"lbm_read_time_us":13693,"lbm_reads_lt_1ms":775,"lbm_write_time_us":34244,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":5632,"thread_start_us":86,"threads_started":1,"update_count":3500}
I20260812 06:16:34.403820  7401 maintenance_manager.cc:419] P 7f80eb985fab48c08bfb6d219c7b7418: Scheduling FlushDeltaMemStoresOp(ca04d86e833d4b898cb28ec8dd64196c): perf score=18.063937
I20260812 06:16:34.464877  7313 maintenance_manager.cc:643] P 7f80eb985fab48c08bfb6d219c7b7418: FlushDeltaMemStoresOp(ca04d86e833d4b898cb28ec8dd64196c) complete. Timing: real 0.061s	user 0.019s	sys 0.038s Metrics: {"bytes_written":20512318,"delete_count":0,"lbm_write_time_us":21703,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:16:34.465430  7401 maintenance_manager.cc:419] P 7f80eb985fab48c08bfb6d219c7b7418: Scheduling FlushDeltaMemStoresOp(ca04d86e833d4b898cb28ec8dd64196c): perf score=2.188937
I20260812 06:16:34.480042  7313 maintenance_manager.cc:643] P 7f80eb985fab48c08bfb6d219c7b7418: FlushDeltaMemStoresOp(ca04d86e833d4b898cb28ec8dd64196c) complete. Timing: real 0.014s	user 0.008s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5600,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:34.480470  7401 maintenance_manager.cc:419] P 7f80eb985fab48c08bfb6d219c7b7418: Scheduling MajorDeltaCompactionOp(ca04d86e833d4b898cb28ec8dd64196c): perf score=1.000000
I20260812 06:16:34.668324  7313 maintenance_manager.cc:643] P 7f80eb985fab48c08bfb6d219c7b7418: MajorDeltaCompactionOp(ca04d86e833d4b898cb28ec8dd64196c) complete. Timing: real 0.188s	user 0.140s	sys 0.048s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918099,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":282,"lbm_read_time_us":12452,"lbm_reads_lt_1ms":672,"lbm_write_time_us":31090,"lbm_writes_lt_1ms":643,"mutex_wait_us":23,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":5376,"update_count":3000}
I20260812 06:16:34.668824  7401 maintenance_manager.cc:419] P 7f80eb985fab48c08bfb6d219c7b7418: Scheduling FlushDeltaMemStoresOp(ca04d86e833d4b898cb28ec8dd64196c): perf score=14.095187
I20260812 06:16:34.715921  7313 maintenance_manager.cc:643] P 7f80eb985fab48c08bfb6d219c7b7418: FlushDeltaMemStoresOp(ca04d86e833d4b898cb28ec8dd64196c) complete. Timing: real 0.047s	user 0.030s	sys 0.012s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":20163,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:34.716387  7401 maintenance_manager.cc:419] P 7f80eb985fab48c08bfb6d219c7b7418: Scheduling FlushDeltaMemStoresOp(ca04d86e833d4b898cb28ec8dd64196c): perf score=2.188937
I20260812 06:16:34.726197  7313 maintenance_manager.cc:643] P 7f80eb985fab48c08bfb6d219c7b7418: FlushDeltaMemStoresOp(ca04d86e833d4b898cb28ec8dd64196c) complete. Timing: real 0.010s	user 0.008s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3760,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:34.726665  7401 maintenance_manager.cc:419] P 7f80eb985fab48c08bfb6d219c7b7418: Scheduling MajorDeltaCompactionOp(ca04d86e833d4b898cb28ec8dd64196c): perf score=1.000000
I20260812 06:16:34.896363  7313 maintenance_manager.cc:643] P 7f80eb985fab48c08bfb6d219c7b7418: MajorDeltaCompactionOp(ca04d86e833d4b898cb28ec8dd64196c) complete. Timing: real 0.169s	user 0.105s	sys 0.059s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":546,"lbm_read_time_us":11322,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26830,"lbm_writes_lt_1ms":543,"mutex_wait_us":304,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5376,"update_count":2500}
I20260812 06:16:34.896829  7401 maintenance_manager.cc:419] P 7f80eb985fab48c08bfb6d219c7b7418: Scheduling FlushDeltaMemStoresOp(ca04d86e833d4b898cb28ec8dd64196c): perf score=14.095187
I20260812 06:16:34.948822  7313 maintenance_manager.cc:643] P 7f80eb985fab48c08bfb6d219c7b7418: FlushDeltaMemStoresOp(ca04d86e833d4b898cb28ec8dd64196c) complete. Timing: real 0.052s	user 0.026s	sys 0.015s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":16086,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:34.949306  7401 maintenance_manager.cc:419] P 7f80eb985fab48c08bfb6d219c7b7418: Scheduling FlushDeltaMemStoresOp(ca04d86e833d4b898cb28ec8dd64196c): perf score=2.188937
I20260812 06:16:34.959024  7313 maintenance_manager.cc:643] P 7f80eb985fab48c08bfb6d219c7b7418: FlushDeltaMemStoresOp(ca04d86e833d4b898cb28ec8dd64196c) complete. Timing: real 0.010s	user 0.008s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3732,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:34.959419  7401 maintenance_manager.cc:419] P 7f80eb985fab48c08bfb6d219c7b7418: Scheduling MajorDeltaCompactionOp(ca04d86e833d4b898cb28ec8dd64196c): perf score=1.000000
I20260812 06:16:35.138590  7313 maintenance_manager.cc:643] P 7f80eb985fab48c08bfb6d219c7b7418: MajorDeltaCompactionOp(ca04d86e833d4b898cb28ec8dd64196c) complete. Timing: real 0.179s	user 0.123s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":766,"lbm_read_time_us":12226,"lbm_reads_lt_1ms":572,"lbm_write_time_us":26136,"lbm_writes_lt_1ms":543,"mutex_wait_us":247,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":3456,"update_count":2500}
I20260812 06:16:35.139092  7401 maintenance_manager.cc:419] P 7f80eb985fab48c08bfb6d219c7b7418: Scheduling FlushDeltaMemStoresOp(ca04d86e833d4b898cb28ec8dd64196c): perf score=14.095187
I20260812 06:16:35.197340  7313 maintenance_manager.cc:643] P 7f80eb985fab48c08bfb6d219c7b7418: FlushDeltaMemStoresOp(ca04d86e833d4b898cb28ec8dd64196c) complete. Timing: real 0.058s	user 0.030s	sys 0.016s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":18056,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:35.197849  7401 maintenance_manager.cc:419] P 7f80eb985fab48c08bfb6d219c7b7418: Scheduling FlushDeltaMemStoresOp(ca04d86e833d4b898cb28ec8dd64196c): perf score=2.188937
I20260812 06:16:35.207528  7313 maintenance_manager.cc:643] P 7f80eb985fab48c08bfb6d219c7b7418: FlushDeltaMemStoresOp(ca04d86e833d4b898cb28ec8dd64196c) complete. Timing: real 0.010s	user 0.000s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3758,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:35.207914  7401 maintenance_manager.cc:419] P 7f80eb985fab48c08bfb6d219c7b7418: Scheduling MajorDeltaCompactionOp(ca04d86e833d4b898cb28ec8dd64196c): perf score=1.000000
I20260812 06:16:35.381350  7313 maintenance_manager.cc:643] P 7f80eb985fab48c08bfb6d219c7b7418: MajorDeltaCompactionOp(ca04d86e833d4b898cb28ec8dd64196c) complete. Timing: real 0.173s	user 0.131s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815685,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":587,"lbm_read_time_us":11365,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27850,"lbm_writes_lt_1ms":543,"mutex_wait_us":299,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11520,"update_count":2500}
I20260812 06:16:35.381934  7401 maintenance_manager.cc:419] P 7f80eb985fab48c08bfb6d219c7b7418: Scheduling FlushDeltaMemStoresOp(ca04d86e833d4b898cb28ec8dd64196c): perf score=11.118625
I20260812 06:16:35.421026  7313 maintenance_manager.cc:643] P 7f80eb985fab48c08bfb6d219c7b7418: FlushDeltaMemStoresOp(ca04d86e833d4b898cb28ec8dd64196c) complete. Timing: real 0.039s	user 0.020s	sys 0.016s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":16898,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":312,"reinsert_count":0,"update_count":1550}
I20260812 06:16:35.421589  7401 maintenance_manager.cc:419] P 7f80eb985fab48c08bfb6d219c7b7418: Scheduling FlushDeltaMemStoresOp(ca04d86e833d4b898cb28ec8dd64196c): perf score=2.188937
I20260812 06:16:35.441264  7313 maintenance_manager.cc:643] P 7f80eb985fab48c08bfb6d219c7b7418: FlushDeltaMemStoresOp(ca04d86e833d4b898cb28ec8dd64196c) complete. Timing: real 0.019s	user 0.002s	sys 0.009s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4681,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:35.441730  7401 maintenance_manager.cc:419] P 7f80eb985fab48c08bfb6d219c7b7418: Scheduling FlushDeltaMemStoresOp(ca04d86e833d4b898cb28ec8dd64196c): perf score=2.188937
I20260812 06:16:35.458276  7313 maintenance_manager.cc:643] P 7f80eb985fab48c08bfb6d219c7b7418: FlushDeltaMemStoresOp(ca04d86e833d4b898cb28ec8dd64196c) complete. Timing: real 0.016s	user 0.003s	sys 0.013s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3458,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:35.458745  7401 maintenance_manager.cc:419] P 7f80eb985fab48c08bfb6d219c7b7418: Scheduling FlushMRSOp(ca04d86e833d4b898cb28ec8dd64196c): perf score=1.000000
I20260812 06:16:35.497233  7313 maintenance_manager.cc:643] P 7f80eb985fab48c08bfb6d219c7b7418: FlushMRSOp(ca04d86e833d4b898cb28ec8dd64196c) complete. Timing: real 0.038s	user 0.025s	sys 0.000s Metrics: {"bytes_written":1152514,"cfile_init":1,"dirs.queue_time_us":54,"dirs.run_cpu_time_us":194,"dirs.run_wall_time_us":1244,"drs_written":1,"lbm_read_time_us":68,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1391,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:16:35.497905  7401 maintenance_manager.cc:419] P 7f80eb985fab48c08bfb6d219c7b7418: Scheduling LogGCOp(ca04d86e833d4b898cb28ec8dd64196c): free 124257256 bytes of WAL
I20260812 06:16:35.498124  7313 log_reader.cc:385] T ca04d86e833d4b898cb28ec8dd64196c: removed 12 log segments from log reader
I20260812 06:16:35.498171  7313 log.cc:1079] T ca04d86e833d4b898cb28ec8dd64196c P 7f80eb985fab48c08bfb6d219c7b7418: Deleting log segment in path: /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386886772-6856-0/minicluster-data/ts-0-root/wals/ca04d86e833d4b898cb28ec8dd64196c/wal-000000014 (ops 66-70)
I20260812 06:16:35.498201  7313 log.cc:1079] T ca04d86e833d4b898cb28ec8dd64196c P 7f80eb985fab48c08bfb6d219c7b7418: Deleting log segment in path: /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386886772-6856-0/minicluster-data/ts-0-root/wals/ca04d86e833d4b898cb28ec8dd64196c/wal-000000015 (ops 71-75)
I20260812 06:16:35.498234  7313 log.cc:1079] T ca04d86e833d4b898cb28ec8dd64196c P 7f80eb985fab48c08bfb6d219c7b7418: Deleting log segment in path: /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386886772-6856-0/minicluster-data/ts-0-root/wals/ca04d86e833d4b898cb28ec8dd64196c/wal-000000016 (ops 76-80)
I20260812 06:16:35.498270  7313 log.cc:1079] T ca04d86e833d4b898cb28ec8dd64196c P 7f80eb985fab48c08bfb6d219c7b7418: Deleting log segment in path: /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386886772-6856-0/minicluster-data/ts-0-root/wals/ca04d86e833d4b898cb28ec8dd64196c/wal-000000017 (ops 81-85)
I20260812 06:16:35.498301  7313 log.cc:1079] T ca04d86e833d4b898cb28ec8dd64196c P 7f80eb985fab48c08bfb6d219c7b7418: Deleting log segment in path: /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386886772-6856-0/minicluster-data/ts-0-root/wals/ca04d86e833d4b898cb28ec8dd64196c/wal-000000018 (ops 86-90)
I20260812 06:16:35.498333  7313 log.cc:1079] T ca04d86e833d4b898cb28ec8dd64196c P 7f80eb985fab48c08bfb6d219c7b7418: Deleting log segment in path: /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386886772-6856-0/minicluster-data/ts-0-root/wals/ca04d86e833d4b898cb28ec8dd64196c/wal-000000019 (ops 91-95)
I20260812 06:16:35.498365  7313 log.cc:1079] T ca04d86e833d4b898cb28ec8dd64196c P 7f80eb985fab48c08bfb6d219c7b7418: Deleting log segment in path: /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386886772-6856-0/minicluster-data/ts-0-root/wals/ca04d86e833d4b898cb28ec8dd64196c/wal-000000020 (ops 96-100)
I20260812 06:16:35.498396  7313 log.cc:1079] T ca04d86e833d4b898cb28ec8dd64196c P 7f80eb985fab48c08bfb6d219c7b7418: Deleting log segment in path: /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386886772-6856-0/minicluster-data/ts-0-root/wals/ca04d86e833d4b898cb28ec8dd64196c/wal-000000021 (ops 101-104)
I20260812 06:16:35.498428  7313 log.cc:1079] T ca04d86e833d4b898cb28ec8dd64196c P 7f80eb985fab48c08bfb6d219c7b7418: Deleting log segment in path: /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386886772-6856-0/minicluster-data/ts-0-root/wals/ca04d86e833d4b898cb28ec8dd64196c/wal-000000022 (ops 105-109)
I20260812 06:16:35.498459  7313 log.cc:1079] T ca04d86e833d4b898cb28ec8dd64196c P 7f80eb985fab48c08bfb6d219c7b7418: Deleting log segment in path: /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386886772-6856-0/minicluster-data/ts-0-root/wals/ca04d86e833d4b898cb28ec8dd64196c/wal-000000023 (ops 110-114)
I20260812 06:16:35.498492  7313 log.cc:1079] T ca04d86e833d4b898cb28ec8dd64196c P 7f80eb985fab48c08bfb6d219c7b7418: Deleting log segment in path: /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386886772-6856-0/minicluster-data/ts-0-root/wals/ca04d86e833d4b898cb28ec8dd64196c/wal-000000024 (ops 115-119)
I20260812 06:16:35.498522  7313 log.cc:1079] T ca04d86e833d4b898cb28ec8dd64196c P 7f80eb985fab48c08bfb6d219c7b7418: Deleting log segment in path: /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386886772-6856-0/minicluster-data/ts-0-root/wals/ca04d86e833d4b898cb28ec8dd64196c/wal-000000025 (ops 120-124)
I20260812 06:16:35.520028  7313 maintenance_manager.cc:643] P 7f80eb985fab48c08bfb6d219c7b7418: LogGCOp(ca04d86e833d4b898cb28ec8dd64196c) complete. Timing: real 0.022s	user 0.000s	sys 0.019s Metrics: {}
I20260812 06:16:35.520457  7401 maintenance_manager.cc:419] P 7f80eb985fab48c08bfb6d219c7b7418: Scheduling FlushDeltaMemStoresOp(ca04d86e833d4b898cb28ec8dd64196c): perf score=3.181125
I20260812 06:16:35.542375  7313 maintenance_manager.cc:643] P 7f80eb985fab48c08bfb6d219c7b7418: FlushDeltaMemStoresOp(ca04d86e833d4b898cb28ec8dd64196c) complete. Timing: real 0.022s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":4052,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:16:35.542835  7401 maintenance_manager.cc:419] P 7f80eb985fab48c08bfb6d219c7b7418: Scheduling UndoDeltaBlockGCOp(ca04d86e833d4b898cb28ec8dd64196c): 447 bytes on disk
I20260812 06:16:35.543237  7313 maintenance_manager.cc:643] P 7f80eb985fab48c08bfb6d219c7b7418: UndoDeltaBlockGCOp(ca04d86e833d4b898cb28ec8dd64196c) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4}
I20260812 06:16:35.543761  7401 maintenance_manager.cc:419] P 7f80eb985fab48c08bfb6d219c7b7418: Scheduling FlushDeltaMemStoresOp(ca04d86e833d4b898cb28ec8dd64196c): perf score=2.188937
I20260812 06:16:35.552565  7313 maintenance_manager.cc:643] P 7f80eb985fab48c08bfb6d219c7b7418: FlushDeltaMemStoresOp(ca04d86e833d4b898cb28ec8dd64196c) complete. Timing: real 0.009s	user 0.007s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3201,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:35.553119  7401 maintenance_manager.cc:419] P 7f80eb985fab48c08bfb6d219c7b7418: Scheduling MajorDeltaCompactionOp(ca04d86e833d4b898cb28ec8dd64196c): perf score=1.000000
I20260812 06:16:35.775683  7313 maintenance_manager.cc:643] P 7f80eb985fab48c08bfb6d219c7b7418: MajorDeltaCompactionOp(ca04d86e833d4b898cb28ec8dd64196c) complete. Timing: real 0.222s	user 0.129s	sys 0.091s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":33020846,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":864,"lbm_read_time_us":14841,"lbm_reads_lt_1ms":775,"lbm_write_time_us":34562,"lbm_writes_lt_1ms":743,"mutex_wait_us":337,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":74,"threads_started":1,"update_count":3500}
I20260812 06:16:35.776206  7401 maintenance_manager.cc:419] P 7f80eb985fab48c08bfb6d219c7b7418: Scheduling FlushDeltaMemStoresOp(ca04d86e833d4b898cb28ec8dd64196c): perf score=18.063937
I20260812 06:16:35.843587  7313 maintenance_manager.cc:643] P 7f80eb985fab48c08bfb6d219c7b7418: FlushDeltaMemStoresOp(ca04d86e833d4b898cb28ec8dd64196c) complete. Timing: real 0.067s	user 0.027s	sys 0.029s Metrics: {"bytes_written":20512313,"delete_count":0,"lbm_write_time_us":25892,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:16:35.844133  7401 maintenance_manager.cc:419] P 7f80eb985fab48c08bfb6d219c7b7418: Scheduling FlushDeltaMemStoresOp(ca04d86e833d4b898cb28ec8dd64196c): perf score=2.188937
I20260812 06:16:35.854290  7313 maintenance_manager.cc:643] P 7f80eb985fab48c08bfb6d219c7b7418: FlushDeltaMemStoresOp(ca04d86e833d4b898cb28ec8dd64196c) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3541,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:35.854722  7401 maintenance_manager.cc:419] P 7f80eb985fab48c08bfb6d219c7b7418: Scheduling MajorDeltaCompactionOp(ca04d86e833d4b898cb28ec8dd64196c): perf score=1.000000
I20260812 06:16:36.034207  7313 maintenance_manager.cc:643] P 7f80eb985fab48c08bfb6d219c7b7418: MajorDeltaCompactionOp(ca04d86e833d4b898cb28ec8dd64196c) complete. Timing: real 0.179s	user 0.120s	sys 0.059s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918095,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":103,"lbm_read_time_us":10983,"lbm_reads_lt_1ms":672,"lbm_write_time_us":28745,"lbm_writes_lt_1ms":643,"mutex_wait_us":26,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":12928,"update_count":3000}
I20260812 06:16:36.039454  7401 maintenance_manager.cc:419] P 7f80eb985fab48c08bfb6d219c7b7418: Scheduling FlushDeltaMemStoresOp(ca04d86e833d4b898cb28ec8dd64196c): perf score=15.087375
I20260812 06:16:36.084120  7313 maintenance_manager.cc:643] P 7f80eb985fab48c08bfb6d219c7b7418: FlushDeltaMemStoresOp(ca04d86e833d4b898cb28ec8dd64196c) complete. Timing: real 0.044s	user 0.030s	sys 0.012s Metrics: {"bytes_written":16820143,"delete_count":0,"lbm_write_time_us":19440,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:16:36.084630  7401 maintenance_manager.cc:419] P 7f80eb985fab48c08bfb6d219c7b7418: Scheduling FlushDeltaMemStoresOp(ca04d86e833d4b898cb28ec8dd64196c): perf score=2.188937
I20260812 06:16:36.105614  7313 maintenance_manager.cc:643] P 7f80eb985fab48c08bfb6d219c7b7418: FlushDeltaMemStoresOp(ca04d86e833d4b898cb28ec8dd64196c) complete. Timing: real 0.021s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5563,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:36.106058  7401 maintenance_manager.cc:419] P 7f80eb985fab48c08bfb6d219c7b7418: Scheduling FlushDeltaMemStoresOp(ca04d86e833d4b898cb28ec8dd64196c): perf score=2.188937
I20260812 06:16:36.118501  7313 maintenance_manager.cc:643] P 7f80eb985fab48c08bfb6d219c7b7418: FlushDeltaMemStoresOp(ca04d86e833d4b898cb28ec8dd64196c) complete. Timing: real 0.012s	user 0.003s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4793,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:36.118978  7401 maintenance_manager.cc:419] P 7f80eb985fab48c08bfb6d219c7b7418: Scheduling MajorDeltaCompactionOp(ca04d86e833d4b898cb28ec8dd64196c): perf score=1.000000
I20260812 06:16:36.311615  7313 maintenance_manager.cc:643] P 7f80eb985fab48c08bfb6d219c7b7418: MajorDeltaCompactionOp(ca04d86e833d4b898cb28ec8dd64196c) complete. Timing: real 0.192s	user 0.125s	sys 0.067s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918202,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":469,"lbm_read_time_us":13892,"lbm_reads_lt_1ms":673,"lbm_write_time_us":30649,"lbm_writes_lt_1ms":643,"mutex_wait_us":255,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":24960,"update_count":3000}
I20260812 06:16:36.313788  7401 maintenance_manager.cc:419] P 7f80eb985fab48c08bfb6d219c7b7418: Scheduling FlushDeltaMemStoresOp(ca04d86e833d4b898cb28ec8dd64196c): perf score=14.095187
I20260812 06:16:36.353082  7313 maintenance_manager.cc:643] P 7f80eb985fab48c08bfb6d219c7b7418: FlushDeltaMemStoresOp(ca04d86e833d4b898cb28ec8dd64196c) complete. Timing: real 0.039s	user 0.022s	sys 0.013s Metrics: {"bytes_written":16409900,"delete_count":0,"lbm_write_time_us":16950,"lbm_writes_lt_1ms":403,"reinsert_count":0,"spinlock_wait_cycles":3328,"update_count":2000}
I20260812 06:16:36.353636  7401 maintenance_manager.cc:419] P 7f80eb985fab48c08bfb6d219c7b7418: Scheduling FlushDeltaMemStoresOp(ca04d86e833d4b898cb28ec8dd64196c): perf score=2.188937
I20260812 06:16:36.371484  7313 maintenance_manager.cc:643] P 7f80eb985fab48c08bfb6d219c7b7418: FlushDeltaMemStoresOp(ca04d86e833d4b898cb28ec8dd64196c) complete. Timing: real 0.018s	user 0.005s	sys 0.009s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6170,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:36.371897  7401 maintenance_manager.cc:419] P 7f80eb985fab48c08bfb6d219c7b7418: Scheduling MajorDeltaCompactionOp(ca04d86e833d4b898cb28ec8dd64196c): perf score=1.000000
I20260812 06:16:36.525732  7313 maintenance_manager.cc:643] P 7f80eb985fab48c08bfb6d219c7b7418: MajorDeltaCompactionOp(ca04d86e833d4b898cb28ec8dd64196c) complete. Timing: real 0.154s	user 0.114s	sys 0.040s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":216,"lbm_read_time_us":11149,"lbm_reads_lt_1ms":568,"lbm_write_time_us":26348,"lbm_writes_lt_1ms":543,"mutex_wait_us":17,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":5376,"update_count":2500}
I20260812 06:16:36.526397  7401 maintenance_manager.cc:419] P 7f80eb985fab48c08bfb6d219c7b7418: Scheduling FlushDeltaMemStoresOp(ca04d86e833d4b898cb28ec8dd64196c): perf score=14.095187
I20260812 06:16:36.578509  7313 maintenance_manager.cc:643] P 7f80eb985fab48c08bfb6d219c7b7418: FlushDeltaMemStoresOp(ca04d86e833d4b898cb28ec8dd64196c) complete. Timing: real 0.052s	user 0.032s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20120,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:36.579056  7401 maintenance_manager.cc:419] P 7f80eb985fab48c08bfb6d219c7b7418: Scheduling FlushDeltaMemStoresOp(ca04d86e833d4b898cb28ec8dd64196c): perf score=2.188937
I20260812 06:16:36.589540  7313 maintenance_manager.cc:643] P 7f80eb985fab48c08bfb6d219c7b7418: FlushDeltaMemStoresOp(ca04d86e833d4b898cb28ec8dd64196c) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3908,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:36.590070  7401 maintenance_manager.cc:419] P 7f80eb985fab48c08bfb6d219c7b7418: Scheduling MajorDeltaCompactionOp(ca04d86e833d4b898cb28ec8dd64196c): perf score=1.000000
I20260812 06:16:36.750056  7313 maintenance_manager.cc:643] P 7f80eb985fab48c08bfb6d219c7b7418: MajorDeltaCompactionOp(ca04d86e833d4b898cb28ec8dd64196c) complete. Timing: real 0.160s	user 0.116s	sys 0.044s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":733,"lbm_read_time_us":10568,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29428,"lbm_writes_lt_1ms":543,"mutex_wait_us":18,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8832,"update_count":2500}
I20260812 06:16:36.750634  7401 maintenance_manager.cc:419] P 7f80eb985fab48c08bfb6d219c7b7418: Scheduling FlushDeltaMemStoresOp(ca04d86e833d4b898cb28ec8dd64196c): perf score=14.095187
I20260812 06:16:36.807588  7313 maintenance_manager.cc:643] P 7f80eb985fab48c08bfb6d219c7b7418: FlushDeltaMemStoresOp(ca04d86e833d4b898cb28ec8dd64196c) complete. Timing: real 0.057s	user 0.031s	sys 0.023s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22292,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:16:36.808139  7401 maintenance_manager.cc:419] P 7f80eb985fab48c08bfb6d219c7b7418: Scheduling FlushDeltaMemStoresOp(ca04d86e833d4b898cb28ec8dd64196c): perf score=2.188937
I20260812 06:16:36.825139  7313 maintenance_manager.cc:643] P 7f80eb985fab48c08bfb6d219c7b7418: FlushDeltaMemStoresOp(ca04d86e833d4b898cb28ec8dd64196c) complete. Timing: real 0.017s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5516,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:36.825626  7401 maintenance_manager.cc:419] P 7f80eb985fab48c08bfb6d219c7b7418: Scheduling FlushMRSOp(ca04d86e833d4b898cb28ec8dd64196c): perf score=1.000000
I20260812 06:16:36.850736  7313 maintenance_manager.cc:643] P 7f80eb985fab48c08bfb6d219c7b7418: FlushMRSOp(ca04d86e833d4b898cb28ec8dd64196c) complete. Timing: real 0.025s	user 0.022s	sys 0.001s Metrics: {"bytes_written":1234475,"cfile_init":1,"dirs.queue_time_us":51,"dirs.run_cpu_time_us":180,"dirs.run_wall_time_us":1030,"drs_written":1,"lbm_read_time_us":35,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1687,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:16:36.851436  7401 maintenance_manager.cc:419] P 7f80eb985fab48c08bfb6d219c7b7418: Scheduling LogGCOp(ca04d86e833d4b898cb28ec8dd64196c): free 120553618 bytes of WAL
I20260812 06:16:36.851670  7313 log_reader.cc:385] T ca04d86e833d4b898cb28ec8dd64196c: removed 12 log segments from log reader
I20260812 06:16:36.851718  7313 log.cc:1079] T ca04d86e833d4b898cb28ec8dd64196c P 7f80eb985fab48c08bfb6d219c7b7418: Deleting log segment in path: /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386886772-6856-0/minicluster-data/ts-0-root/wals/ca04d86e833d4b898cb28ec8dd64196c/wal-000000026 (ops 125-129)
I20260812 06:16:36.851747  7313 log.cc:1079] T ca04d86e833d4b898cb28ec8dd64196c P 7f80eb985fab48c08bfb6d219c7b7418: Deleting log segment in path: /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386886772-6856-0/minicluster-data/ts-0-root/wals/ca04d86e833d4b898cb28ec8dd64196c/wal-000000027 (ops 130-134)
I20260812 06:16:36.851763  7313 log.cc:1079] T ca04d86e833d4b898cb28ec8dd64196c P 7f80eb985fab48c08bfb6d219c7b7418: Deleting log segment in path: /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386886772-6856-0/minicluster-data/ts-0-root/wals/ca04d86e833d4b898cb28ec8dd64196c/wal-000000028 (ops 135-138)
I20260812 06:16:36.851790  7313 log.cc:1079] T ca04d86e833d4b898cb28ec8dd64196c P 7f80eb985fab48c08bfb6d219c7b7418: Deleting log segment in path: /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386886772-6856-0/minicluster-data/ts-0-root/wals/ca04d86e833d4b898cb28ec8dd64196c/wal-000000029 (ops 139-143)
I20260812 06:16:36.851822  7313 log.cc:1079] T ca04d86e833d4b898cb28ec8dd64196c P 7f80eb985fab48c08bfb6d219c7b7418: Deleting log segment in path: /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386886772-6856-0/minicluster-data/ts-0-root/wals/ca04d86e833d4b898cb28ec8dd64196c/wal-000000030 (ops 144-148)
I20260812 06:16:36.851854  7313 log.cc:1079] T ca04d86e833d4b898cb28ec8dd64196c P 7f80eb985fab48c08bfb6d219c7b7418: Deleting log segment in path: /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386886772-6856-0/minicluster-data/ts-0-root/wals/ca04d86e833d4b898cb28ec8dd64196c/wal-000000031 (ops 149-153)
I20260812 06:16:36.851886  7313 log.cc:1079] T ca04d86e833d4b898cb28ec8dd64196c P 7f80eb985fab48c08bfb6d219c7b7418: Deleting log segment in path: /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386886772-6856-0/minicluster-data/ts-0-root/wals/ca04d86e833d4b898cb28ec8dd64196c/wal-000000032 (ops 154-158)
I20260812 06:16:36.851915  7313 log.cc:1079] T ca04d86e833d4b898cb28ec8dd64196c P 7f80eb985fab48c08bfb6d219c7b7418: Deleting log segment in path: /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386886772-6856-0/minicluster-data/ts-0-root/wals/ca04d86e833d4b898cb28ec8dd64196c/wal-000000033 (ops 159-163)
I20260812 06:16:36.851945  7313 log.cc:1079] T ca04d86e833d4b898cb28ec8dd64196c P 7f80eb985fab48c08bfb6d219c7b7418: Deleting log segment in path: /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386886772-6856-0/minicluster-data/ts-0-root/wals/ca04d86e833d4b898cb28ec8dd64196c/wal-000000034 (ops 164-168)
I20260812 06:16:36.851977  7313 log.cc:1079] T ca04d86e833d4b898cb28ec8dd64196c P 7f80eb985fab48c08bfb6d219c7b7418: Deleting log segment in path: /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386886772-6856-0/minicluster-data/ts-0-root/wals/ca04d86e833d4b898cb28ec8dd64196c/wal-000000035 (ops 169-173)
I20260812 06:16:36.852021  7313 log.cc:1079] T ca04d86e833d4b898cb28ec8dd64196c P 7f80eb985fab48c08bfb6d219c7b7418: Deleting log segment in path: /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386886772-6856-0/minicluster-data/ts-0-root/wals/ca04d86e833d4b898cb28ec8dd64196c/wal-000000036 (ops 174-178)
I20260812 06:16:36.852053  7313 log.cc:1079] T ca04d86e833d4b898cb28ec8dd64196c P 7f80eb985fab48c08bfb6d219c7b7418: Deleting log segment in path: /tmp/dist-test-taskNqdEny/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515386886772-6856-0/minicluster-data/ts-0-root/wals/ca04d86e833d4b898cb28ec8dd64196c/wal-000000037 (ops 179-182)
I20260812 06:16:36.871533  7313 maintenance_manager.cc:643] P 7f80eb985fab48c08bfb6d219c7b7418: LogGCOp(ca04d86e833d4b898cb28ec8dd64196c) complete. Timing: real 0.020s	user 0.000s	sys 0.018s Metrics: {}
I20260812 06:16:36.871924  7401 maintenance_manager.cc:419] P 7f80eb985fab48c08bfb6d219c7b7418: Scheduling UndoDeltaBlockGCOp(ca04d86e833d4b898cb28ec8dd64196c): 472 bytes on disk
I20260812 06:16:36.872463  7313 maintenance_manager.cc:643] P 7f80eb985fab48c08bfb6d219c7b7418: UndoDeltaBlockGCOp(ca04d86e833d4b898cb28ec8dd64196c) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":68,"lbm_reads_lt_1ms":4}
I20260812 06:16:36.872987  7401 maintenance_manager.cc:419] P 7f80eb985fab48c08bfb6d219c7b7418: Scheduling FlushDeltaMemStoresOp(ca04d86e833d4b898cb28ec8dd64196c): perf score=3.181125
I20260812 06:16:36.891458  7313 maintenance_manager.cc:643] P 7f80eb985fab48c08bfb6d219c7b7418: FlushDeltaMemStoresOp(ca04d86e833d4b898cb28ec8dd64196c) complete. Timing: real 0.018s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":4215,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:16:36.891892  7401 maintenance_manager.cc:419] P 7f80eb985fab48c08bfb6d219c7b7418: Scheduling FlushDeltaMemStoresOp(ca04d86e833d4b898cb28ec8dd64196c): perf score=2.188937
I20260812 06:16:36.900570  7313 maintenance_manager.cc:643] P 7f80eb985fab48c08bfb6d219c7b7418: FlushDeltaMemStoresOp(ca04d86e833d4b898cb28ec8dd64196c) complete. Timing: real 0.009s	user 0.000s	sys 0.007s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3286,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:16:36.901062  7401 maintenance_manager.cc:419] P 7f80eb985fab48c08bfb6d219c7b7418: Scheduling MajorDeltaCompactionOp(ca04d86e833d4b898cb28ec8dd64196c): perf score=1.000000
I20260812 06:16:37.110450  7313 maintenance_manager.cc:643] P 7f80eb985fab48c08bfb6d219c7b7418: MajorDeltaCompactionOp(ca04d86e833d4b898cb28ec8dd64196c) complete. Timing: real 0.209s	user 0.147s	sys 0.060s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020731,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":831,"lbm_read_time_us":14188,"lbm_reads_lt_1ms":774,"lbm_write_time_us":38707,"lbm_writes_lt_1ms":743,"mutex_wait_us":274,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":4224,"thread_start_us":75,"threads_started":1,"update_count":3500}
I20260812 06:16:37.111027  7401 maintenance_manager.cc:419] P 7f80eb985fab48c08bfb6d219c7b7418: Scheduling FlushDeltaMemStoresOp(ca04d86e833d4b898cb28ec8dd64196c): perf score=18.063937
I20260812 06:16:37.157940  7313 maintenance_manager.cc:643] P 7f80eb985fab48c08bfb6d219c7b7418: FlushDeltaMemStoresOp(ca04d86e833d4b898cb28ec8dd64196c) complete. Timing: real 0.047s	user 0.037s	sys 0.009s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":19871,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:16:37.158691  7401 maintenance_manager.cc:419] P 7f80eb985fab48c08bfb6d219c7b7418: Scheduling FlushDeltaMemStoresOp(ca04d86e833d4b898cb28ec8dd64196c): perf score=2.188937
I20260812 06:16:37.183869  7313 maintenance_manager.cc:643] P 7f80eb985fab48c08bfb6d219c7b7418: FlushDeltaMemStoresOp(ca04d86e833d4b898cb28ec8dd64196c) complete. Timing: real 0.025s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4718,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:37.184324  7401 maintenance_manager.cc:419] P 7f80eb985fab48c08bfb6d219c7b7418: Scheduling FlushDeltaMemStoresOp(ca04d86e833d4b898cb28ec8dd64196c): perf score=2.188937
I20260812 06:16:37.198179  7313 maintenance_manager.cc:643] P 7f80eb985fab48c08bfb6d219c7b7418: FlushDeltaMemStoresOp(ca04d86e833d4b898cb28ec8dd64196c) complete. Timing: real 0.014s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5317,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:16:37.198590  7401 maintenance_manager.cc:419] P 7f80eb985fab48c08bfb6d219c7b7418: Scheduling MajorDeltaCompactionOp(ca04d86e833d4b898cb28ec8dd64196c): perf score=1.000000
I20260812 06:16:37.231971  6856 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.526s	user 1.670s	sys 0.172s
I20260812 06:16:37.291631  6856 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.059s	user 0.001s	sys 0.000s
I20260812 06:16:37.292111  6856 tablet_server.cc:179] TabletServer@127.6.178.1:0 shutting down...
I20260812 06:16:37.359699  7313 maintenance_manager.cc:643] P 7f80eb985fab48c08bfb6d219c7b7418: MajorDeltaCompactionOp(ca04d86e833d4b898cb28ec8dd64196c) complete. Timing: real 0.161s	user 0.120s	sys 0.040s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":33020630,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1064,"lbm_read_time_us":12975,"lbm_reads_lt_1ms":769,"lbm_write_time_us":33651,"lbm_writes_lt_1ms":743,"mutex_wait_us":368,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":35712,"update_count":3500}
I20260812 06:16:37.360265  6856 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:16:37.360459  6856 tablet_replica.cc:333] T ca04d86e833d4b898cb28ec8dd64196c P 7f80eb985fab48c08bfb6d219c7b7418: stopping tablet replica
I20260812 06:16:37.360611  6856 raft_consensus.cc:2243] T ca04d86e833d4b898cb28ec8dd64196c P 7f80eb985fab48c08bfb6d219c7b7418 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:37.360767  6856 raft_consensus.cc:2272] T ca04d86e833d4b898cb28ec8dd64196c P 7f80eb985fab48c08bfb6d219c7b7418 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:37.365314  6856 tablet_server.cc:196] TabletServer@127.6.178.1:0 shutdown complete.
I20260812 06:16:37.417361  6856 master.cc:562] Master@127.6.178.62:34073 shutting down...
I20260812 06:16:37.420562  6856 raft_consensus.cc:2243] T 00000000000000000000000000000000 P e647c60dce764322811cca21850c941f [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:16:37.420732  6856 raft_consensus.cc:2272] T 00000000000000000000000000000000 P e647c60dce764322811cca21850c941f [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:16:37.420795  6856 tablet_replica.cc:333] T 00000000000000000000000000000000 P e647c60dce764322811cca21850c941f: stopping tablet replica
I20260812 06:16:37.432794  6856 master.cc:584] Master@127.6.178.62:34073 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (4999 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10606 ms total)

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