[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:18:14.147863 11097 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.10.214.126:46093
I20260812 06:18:14.149013 11097 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:18:14.149652 11097 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:14.156201 11106 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:14.156492 11097 server_base.cc:1061] running on GCE node
W20260812 06:18:14.156533 11105 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:14.156527 11109 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:14.157217 11097 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:14.157337 11097 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:14.157389 11097 hybrid_clock.cc:648] HybridClock initialized: now 1786515494157387 us; error 0 us; skew 500 ppm
I20260812 06:18:14.159348 11097 webserver.cc:533] Webserver started at http://127.10.214.126:46761/ using document root <none> and password file <none>
I20260812 06:18:14.159924 11097 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:14.160006 11097 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:14.160295 11097 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:14.162035 11097 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515494136637-11097-0/minicluster-data/master-0-root/instance:
uuid: "301bfd7d44154c0e953fa9734d12d18c"
format_stamp: "Formatted at 2026-08-12 06:18:14 on dist-test-slave-x5fp"
I20260812 06:18:14.165747 11097 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.004s	sys 0.000s
I20260812 06:18:14.168136 11118 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:14.169268 11097 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.001s
I20260812 06:18:14.169397 11097 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515494136637-11097-0/minicluster-data/master-0-root
uuid: "301bfd7d44154c0e953fa9734d12d18c"
format_stamp: "Formatted at 2026-08-12 06:18:14 on dist-test-slave-x5fp"
I20260812 06:18:14.169514 11097 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515494136637-11097-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515494136637-11097-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515494136637-11097-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:14.178736 11097 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:14.179302 11097 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:18:14.179483 11097 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:14.186882 11097 rpc_server.cc:307] RPC server started. Bound to: 127.10.214.126:46093
I20260812 06:18:14.186887 11196 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.10.214.126:46093 every 8 connection(s)
I20260812 06:18:14.189057 11197 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:14.194293 11197 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 301bfd7d44154c0e953fa9734d12d18c: Bootstrap starting.
I20260812 06:18:14.196544 11197 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 301bfd7d44154c0e953fa9734d12d18c: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:14.197440 11197 log.cc:826] T 00000000000000000000000000000000 P 301bfd7d44154c0e953fa9734d12d18c: Log is configured to *not* fsync() on all Append() calls
I20260812 06:18:14.199095 11197 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 301bfd7d44154c0e953fa9734d12d18c: No bootstrap required, opened a new log
I20260812 06:18:14.201833 11197 raft_consensus.cc:359] T 00000000000000000000000000000000 P 301bfd7d44154c0e953fa9734d12d18c [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "301bfd7d44154c0e953fa9734d12d18c" member_type: VOTER }
I20260812 06:18:14.201988 11197 raft_consensus.cc:385] T 00000000000000000000000000000000 P 301bfd7d44154c0e953fa9734d12d18c [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:14.202093 11197 raft_consensus.cc:740] T 00000000000000000000000000000000 P 301bfd7d44154c0e953fa9734d12d18c [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 301bfd7d44154c0e953fa9734d12d18c, State: Initialized, Role: FOLLOWER
I20260812 06:18:14.202726 11197 consensus_queue.cc:260] T 00000000000000000000000000000000 P 301bfd7d44154c0e953fa9734d12d18c [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: "301bfd7d44154c0e953fa9734d12d18c" member_type: VOTER }
I20260812 06:18:14.202894 11197 raft_consensus.cc:399] T 00000000000000000000000000000000 P 301bfd7d44154c0e953fa9734d12d18c [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:14.202965 11197 raft_consensus.cc:493] T 00000000000000000000000000000000 P 301bfd7d44154c0e953fa9734d12d18c [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:14.203104 11197 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 301bfd7d44154c0e953fa9734d12d18c [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:14.203855 11197 raft_consensus.cc:515] T 00000000000000000000000000000000 P 301bfd7d44154c0e953fa9734d12d18c [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "301bfd7d44154c0e953fa9734d12d18c" member_type: VOTER }
I20260812 06:18:14.204285 11197 leader_election.cc:304] T 00000000000000000000000000000000 P 301bfd7d44154c0e953fa9734d12d18c [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: 301bfd7d44154c0e953fa9734d12d18c; no voters: 
I20260812 06:18:14.204614 11197 leader_election.cc:290] T 00000000000000000000000000000000 P 301bfd7d44154c0e953fa9734d12d18c [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:14.204957 11201 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 301bfd7d44154c0e953fa9734d12d18c [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:14.205207 11201 raft_consensus.cc:697] T 00000000000000000000000000000000 P 301bfd7d44154c0e953fa9734d12d18c [term 1 LEADER]: Becoming Leader. State: Replica: 301bfd7d44154c0e953fa9734d12d18c, State: Running, Role: LEADER
I20260812 06:18:14.205561 11201 consensus_queue.cc:237] T 00000000000000000000000000000000 P 301bfd7d44154c0e953fa9734d12d18c [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: "301bfd7d44154c0e953fa9734d12d18c" member_type: VOTER }
I20260812 06:18:14.205613 11197 sys_catalog.cc:565] T 00000000000000000000000000000000 P 301bfd7d44154c0e953fa9734d12d18c [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:14.207574 11204 sys_catalog.cc:455] T 00000000000000000000000000000000 P 301bfd7d44154c0e953fa9734d12d18c [sys.catalog]: SysCatalogTable state changed. Reason: New leader 301bfd7d44154c0e953fa9734d12d18c. Latest consensus state: current_term: 1 leader_uuid: "301bfd7d44154c0e953fa9734d12d18c" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "301bfd7d44154c0e953fa9734d12d18c" member_type: VOTER } }
I20260812 06:18:14.207609 11202 sys_catalog.cc:455] T 00000000000000000000000000000000 P 301bfd7d44154c0e953fa9734d12d18c [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "301bfd7d44154c0e953fa9734d12d18c" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "301bfd7d44154c0e953fa9734d12d18c" member_type: VOTER } }
I20260812 06:18:14.207702 11204 sys_catalog.cc:458] T 00000000000000000000000000000000 P 301bfd7d44154c0e953fa9734d12d18c [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:14.207716 11202 sys_catalog.cc:458] T 00000000000000000000000000000000 P 301bfd7d44154c0e953fa9734d12d18c [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:14.208101 11218 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:14.208127 11097 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:14.210409 11218 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:14.215135 11218 catalog_manager.cc:1383] Generated new cluster ID: ab725f9744d947bda3e828d05088dff9
I20260812 06:18:14.215219 11218 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:14.223332 11218 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:14.224397 11218 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:14.230640 11218 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 301bfd7d44154c0e953fa9734d12d18c: Generated new TSK 0
I20260812 06:18:14.231259 11218 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:14.240787 11097 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:14.243482 11225 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:14.243535 11226 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:14.243696 11228 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:14.243882 11097 server_base.cc:1061] running on GCE node
I20260812 06:18:14.244052 11097 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:14.244096 11097 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:14.244118 11097 hybrid_clock.cc:648] HybridClock initialized: now 1786515494244118 us; error 0 us; skew 500 ppm
I20260812 06:18:14.245102 11097 webserver.cc:533] Webserver started at http://127.10.214.65:44075/ using document root <none> and password file <none>
I20260812 06:18:14.245280 11097 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:14.245340 11097 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:14.245409 11097 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:14.245843 11097 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515494136637-11097-0/minicluster-data/ts-0-root/instance:
uuid: "5f8119c610d94c448bd970de9162c271"
format_stamp: "Formatted at 2026-08-12 06:18:14 on dist-test-slave-x5fp"
I20260812 06:18:14.247660 11097 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:18:14.248838 11234 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:14.249106 11097 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:18:14.249182 11097 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515494136637-11097-0/minicluster-data/ts-0-root
uuid: "5f8119c610d94c448bd970de9162c271"
format_stamp: "Formatted at 2026-08-12 06:18:14 on dist-test-slave-x5fp"
I20260812 06:18:14.249274 11097 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515494136637-11097-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515494136637-11097-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515494136637-11097-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:14.269619 11097 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:14.270138 11097 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:14.270710 11097 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:14.271588 11097 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:14.271641 11097 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:14.271711 11097 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:14.271754 11097 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:14.278599 11097 rpc_server.cc:307] RPC server started. Bound to: 127.10.214.65:40185
I20260812 06:18:14.278638 11329 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.10.214.65:40185 every 8 connection(s)
I20260812 06:18:14.292073 11330 heartbeater.cc:344] Connected to a master server at 127.10.214.126:46093
I20260812 06:18:14.292351 11330 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:14.292918 11330 heartbeater.cc:507] Master 127.10.214.126:46093 requested a full tablet report, sending...
I20260812 06:18:14.294426 11141 ts_manager.cc:194] Registered new tserver with Master: 5f8119c610d94c448bd970de9162c271 (127.10.214.65:40185)
I20260812 06:18:14.294962 11097 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.015703281s
I20260812 06:18:14.296011 11141 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:49492
I20260812 06:18:14.304983 11141 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:49508:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:18:14.319664 11283 tablet_service.cc:1511] Processing CreateTablet for tablet 83f36c6eb02c4725b7837f77d761331e (DEFAULT_TABLE table=heavy-update-compaction-test [id=f1b41270c4724f09a40c11726c6a8b7c]), partition=
I20260812 06:18:14.320112 11283 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 83f36c6eb02c4725b7837f77d761331e. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:14.322371 11353 tablet_bootstrap.cc:492] T 83f36c6eb02c4725b7837f77d761331e P 5f8119c610d94c448bd970de9162c271: Bootstrap starting.
I20260812 06:18:14.323473 11353 tablet_bootstrap.cc:654] T 83f36c6eb02c4725b7837f77d761331e P 5f8119c610d94c448bd970de9162c271: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:14.324802 11353 tablet_bootstrap.cc:492] T 83f36c6eb02c4725b7837f77d761331e P 5f8119c610d94c448bd970de9162c271: No bootstrap required, opened a new log
I20260812 06:18:14.324905 11353 ts_tablet_manager.cc:1403] T 83f36c6eb02c4725b7837f77d761331e P 5f8119c610d94c448bd970de9162c271: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:18:14.325479 11353 raft_consensus.cc:359] T 83f36c6eb02c4725b7837f77d761331e P 5f8119c610d94c448bd970de9162c271 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5f8119c610d94c448bd970de9162c271" member_type: VOTER last_known_addr { host: "127.10.214.65" port: 40185 } }
I20260812 06:18:14.325649 11353 raft_consensus.cc:385] T 83f36c6eb02c4725b7837f77d761331e P 5f8119c610d94c448bd970de9162c271 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:14.325686 11353 raft_consensus.cc:740] T 83f36c6eb02c4725b7837f77d761331e P 5f8119c610d94c448bd970de9162c271 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 5f8119c610d94c448bd970de9162c271, State: Initialized, Role: FOLLOWER
I20260812 06:18:14.325831 11353 consensus_queue.cc:260] T 83f36c6eb02c4725b7837f77d761331e P 5f8119c610d94c448bd970de9162c271 [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: "5f8119c610d94c448bd970de9162c271" member_type: VOTER last_known_addr { host: "127.10.214.65" port: 40185 } }
I20260812 06:18:14.325937 11353 raft_consensus.cc:399] T 83f36c6eb02c4725b7837f77d761331e P 5f8119c610d94c448bd970de9162c271 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:14.326027 11353 raft_consensus.cc:493] T 83f36c6eb02c4725b7837f77d761331e P 5f8119c610d94c448bd970de9162c271 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:14.326087 11353 raft_consensus.cc:3060] T 83f36c6eb02c4725b7837f77d761331e P 5f8119c610d94c448bd970de9162c271 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:14.327099 11353 raft_consensus.cc:515] T 83f36c6eb02c4725b7837f77d761331e P 5f8119c610d94c448bd970de9162c271 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5f8119c610d94c448bd970de9162c271" member_type: VOTER last_known_addr { host: "127.10.214.65" port: 40185 } }
I20260812 06:18:14.327296 11353 leader_election.cc:304] T 83f36c6eb02c4725b7837f77d761331e P 5f8119c610d94c448bd970de9162c271 [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: 5f8119c610d94c448bd970de9162c271; no voters: 
I20260812 06:18:14.327509 11353 leader_election.cc:290] T 83f36c6eb02c4725b7837f77d761331e P 5f8119c610d94c448bd970de9162c271 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:14.327667 11355 raft_consensus.cc:2804] T 83f36c6eb02c4725b7837f77d761331e P 5f8119c610d94c448bd970de9162c271 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:14.327912 11353 ts_tablet_manager.cc:1434] T 83f36c6eb02c4725b7837f77d761331e P 5f8119c610d94c448bd970de9162c271: Time spent starting tablet: real 0.003s	user 0.003s	sys 0.000s
I20260812 06:18:14.327942 11355 raft_consensus.cc:697] T 83f36c6eb02c4725b7837f77d761331e P 5f8119c610d94c448bd970de9162c271 [term 1 LEADER]: Becoming Leader. State: Replica: 5f8119c610d94c448bd970de9162c271, State: Running, Role: LEADER
I20260812 06:18:14.328135 11330 heartbeater.cc:499] Master 127.10.214.126:46093 was elected leader, sending a full tablet report...
I20260812 06:18:14.328301 11355 consensus_queue.cc:237] T 83f36c6eb02c4725b7837f77d761331e P 5f8119c610d94c448bd970de9162c271 [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: "5f8119c610d94c448bd970de9162c271" member_type: VOTER last_known_addr { host: "127.10.214.65" port: 40185 } }
I20260812 06:18:14.331101 11141 catalog_manager.cc:5719] T 83f36c6eb02c4725b7837f77d761331e P 5f8119c610d94c448bd970de9162c271 reported cstate change: term changed from 0 to 1, leader changed from <none> to 5f8119c610d94c448bd970de9162c271 (127.10.214.65). New cstate: current_term: 1 leader_uuid: "5f8119c610d94c448bd970de9162c271" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "5f8119c610d94c448bd970de9162c271" member_type: VOTER last_known_addr { host: "127.10.214.65" port: 40185 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:14.395777 11097 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.055s	user 0.024s	sys 0.004s
I20260812 06:18:14.529651 11331 maintenance_manager.cc:419] P 5f8119c610d94c448bd970de9162c271: Scheduling FlushMRSOp(83f36c6eb02c4725b7837f77d761331e): perf score=19.054940
I20260812 06:18:14.715144 11240 maintenance_manager.cc:643] P 5f8119c610d94c448bd970de9162c271: FlushMRSOp(83f36c6eb02c4725b7837f77d761331e) complete. Timing: real 0.185s	user 0.148s	sys 0.032s Metrics: {"bytes_written":13251053,"cfile_init":1,"compiler_manager_pool.queue_time_us":272,"delete_count":0,"dirs.queue_time_us":38,"dirs.run_cpu_time_us":273,"dirs.run_wall_time_us":916,"drs_written":1,"lbm_read_time_us":76,"lbm_reads_lt_1ms":4,"lbm_write_time_us":46920,"lbm_writes_lt_1ms":780,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":395008,"thread_start_us":162,"threads_started":1,"update_count":1615}
I20260812 06:18:14.716188 11331 maintenance_manager.cc:419] P 5f8119c610d94c448bd970de9162c271: Scheduling LogGCOp(83f36c6eb02c4725b7837f77d761331e): free 20290830 bytes of WAL
I20260812 06:18:14.716490 11240 log_reader.cc:385] T 83f36c6eb02c4725b7837f77d761331e: removed 2 log segments from log reader
I20260812 06:18:14.716571 11240 log.cc:1079] T 83f36c6eb02c4725b7837f77d761331e P 5f8119c610d94c448bd970de9162c271: Deleting log segment in path: /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515494136637-11097-0/minicluster-data/ts-0-root/wals/83f36c6eb02c4725b7837f77d761331e/wal-000000001 (ops 1-6)
I20260812 06:18:14.716648 11240 log.cc:1079] T 83f36c6eb02c4725b7837f77d761331e P 5f8119c610d94c448bd970de9162c271: Deleting log segment in path: /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515494136637-11097-0/minicluster-data/ts-0-root/wals/83f36c6eb02c4725b7837f77d761331e/wal-000000002 (ops 7-10)
I20260812 06:18:14.720968 11240 maintenance_manager.cc:643] P 5f8119c610d94c448bd970de9162c271: LogGCOp(83f36c6eb02c4725b7837f77d761331e) complete. Timing: real 0.005s	user 0.001s	sys 0.003s Metrics: {}
I20260812 06:18:14.721280 11331 maintenance_manager.cc:419] P 5f8119c610d94c448bd970de9162c271: Scheduling FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e): perf score=3.181125
I20260812 06:18:14.740844 11240 maintenance_manager.cc:643] P 5f8119c610d94c448bd970de9162c271: FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e) complete. Timing: real 0.019s	user 0.008s	sys 0.012s Metrics: {"bytes_written":4471882,"delete_count":0,"lbm_write_time_us":4442,"lbm_writes_lt_1ms":112,"reinsert_count":0,"update_count":545}
I20260812 06:18:14.741345 11331 maintenance_manager.cc:419] P 5f8119c610d94c448bd970de9162c271: Scheduling UndoDeltaBlockGCOp(83f36c6eb02c4725b7837f77d761331e): 16411392 bytes on disk
I20260812 06:18:14.741986 11240 maintenance_manager.cc:643] P 5f8119c610d94c448bd970de9162c271: UndoDeltaBlockGCOp(83f36c6eb02c4725b7837f77d761331e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":79,"lbm_reads_lt_1ms":4}
I20260812 06:18:14.742427 11331 maintenance_manager.cc:419] P 5f8119c610d94c448bd970de9162c271: Scheduling FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e): perf score=1.196750
I20260812 06:18:14.753796 11240 maintenance_manager.cc:643] P 5f8119c610d94c448bd970de9162c271: FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":2789855,"delete_count":0,"lbm_write_time_us":4058,"lbm_writes_lt_1ms":71,"reinsert_count":0,"update_count":340}
I20260812 06:18:14.754376 11331 maintenance_manager.cc:419] P 5f8119c610d94c448bd970de9162c271: Scheduling MajorDeltaCompactionOp(83f36c6eb02c4725b7837f77d761331e): perf score=1.000000
I20260812 06:18:14.932837 11240 maintenance_manager.cc:643] P 5f8119c610d94c448bd970de9162c271: MajorDeltaCompactionOp(83f36c6eb02c4725b7837f77d761331e) complete. Timing: real 0.178s	user 0.112s	sys 0.065s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774790,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":960,"lbm_read_time_us":13534,"lbm_reads_lt_1ms":569,"lbm_write_time_us":30443,"lbm_writes_lt_1ms":543,"mutex_wait_us":49,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10240,"thread_start_us":356,"threads_started":5,"update_count":2500}
I20260812 06:18:14.933293 11331 maintenance_manager.cc:419] P 5f8119c610d94c448bd970de9162c271: Scheduling FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e): perf score=10.126437
I20260812 06:18:14.982774 11240 maintenance_manager.cc:643] P 5f8119c610d94c448bd970de9162c271: FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e) complete. Timing: real 0.049s	user 0.015s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14260,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:14.983327 11331 maintenance_manager.cc:419] P 5f8119c610d94c448bd970de9162c271: Scheduling FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e): perf score=2.188937
I20260812 06:18:14.994072 11240 maintenance_manager.cc:643] P 5f8119c610d94c448bd970de9162c271: FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e) complete. Timing: real 0.011s	user 0.008s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3871,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:14.994582 11331 maintenance_manager.cc:419] P 5f8119c610d94c448bd970de9162c271: Scheduling MajorDeltaCompactionOp(83f36c6eb02c4725b7837f77d761331e): perf score=1.000000
I20260812 06:18:15.138067 11240 maintenance_manager.cc:643] P 5f8119c610d94c448bd970de9162c271: MajorDeltaCompactionOp(83f36c6eb02c4725b7837f77d761331e) complete. Timing: real 0.143s	user 0.128s	sys 0.012s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":367,"lbm_read_time_us":8983,"lbm_reads_lt_1ms":472,"lbm_write_time_us":29396,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4480,"update_count":2000}
I20260812 06:18:15.138815 11331 maintenance_manager.cc:419] P 5f8119c610d94c448bd970de9162c271: Scheduling FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e): perf score=10.126437
I20260812 06:18:15.180702 11240 maintenance_manager.cc:643] P 5f8119c610d94c448bd970de9162c271: FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e) complete. Timing: real 0.042s	user 0.022s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16801,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:15.181211 11331 maintenance_manager.cc:419] P 5f8119c610d94c448bd970de9162c271: Scheduling FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e): perf score=2.188937
I20260812 06:18:15.191809 11240 maintenance_manager.cc:643] P 5f8119c610d94c448bd970de9162c271: FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4011,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:15.192394 11331 maintenance_manager.cc:419] P 5f8119c610d94c448bd970de9162c271: Scheduling MajorDeltaCompactionOp(83f36c6eb02c4725b7837f77d761331e): perf score=1.000000
I20260812 06:18:15.320924 11240 maintenance_manager.cc:643] P 5f8119c610d94c448bd970de9162c271: MajorDeltaCompactionOp(83f36c6eb02c4725b7837f77d761331e) complete. Timing: real 0.128s	user 0.090s	sys 0.038s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":159,"lbm_read_time_us":9681,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25333,"lbm_writes_lt_1ms":443,"mutex_wait_us":21,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":3328,"update_count":2000}
I20260812 06:18:15.321533 11331 maintenance_manager.cc:419] P 5f8119c610d94c448bd970de9162c271: Scheduling FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e): perf score=10.126437
I20260812 06:18:15.367709 11240 maintenance_manager.cc:643] P 5f8119c610d94c448bd970de9162c271: FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e) complete. Timing: real 0.046s	user 0.028s	sys 0.005s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":15689,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:15.368218 11331 maintenance_manager.cc:419] P 5f8119c610d94c448bd970de9162c271: Scheduling FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e): perf score=2.188937
I20260812 06:18:15.378952 11240 maintenance_manager.cc:643] P 5f8119c610d94c448bd970de9162c271: FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e) complete. Timing: real 0.011s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4002,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:15.379590 11331 maintenance_manager.cc:419] P 5f8119c610d94c448bd970de9162c271: Scheduling MajorDeltaCompactionOp(83f36c6eb02c4725b7837f77d761331e): perf score=1.000000
I20260812 06:18:15.501919 11240 maintenance_manager.cc:643] P 5f8119c610d94c448bd970de9162c271: MajorDeltaCompactionOp(83f36c6eb02c4725b7837f77d761331e) complete. Timing: real 0.122s	user 0.098s	sys 0.024s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":522,"lbm_read_time_us":9163,"lbm_reads_lt_1ms":472,"lbm_write_time_us":22777,"lbm_writes_lt_1ms":443,"mutex_wait_us":262,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:15.502569 11331 maintenance_manager.cc:419] P 5f8119c610d94c448bd970de9162c271: Scheduling FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e): perf score=10.126437
I20260812 06:18:15.545836 11240 maintenance_manager.cc:643] P 5f8119c610d94c448bd970de9162c271: FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e) complete. Timing: real 0.043s	user 0.023s	sys 0.019s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14918,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:15.546458 11331 maintenance_manager.cc:419] P 5f8119c610d94c448bd970de9162c271: Scheduling FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e): perf score=2.188937
I20260812 06:18:15.557598 11240 maintenance_manager.cc:643] P 5f8119c610d94c448bd970de9162c271: FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e) complete. Timing: real 0.011s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4386,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:15.558022 11331 maintenance_manager.cc:419] P 5f8119c610d94c448bd970de9162c271: Scheduling MajorDeltaCompactionOp(83f36c6eb02c4725b7837f77d761331e): perf score=1.000000
I20260812 06:18:15.702729 11240 maintenance_manager.cc:643] P 5f8119c610d94c448bd970de9162c271: MajorDeltaCompactionOp(83f36c6eb02c4725b7837f77d761331e) complete. Timing: real 0.145s	user 0.098s	sys 0.046s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672276,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":276,"lbm_read_time_us":10911,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23575,"lbm_writes_lt_1ms":443,"mutex_wait_us":23,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":6912,"update_count":2000}
I20260812 06:18:15.703405 11331 maintenance_manager.cc:419] P 5f8119c610d94c448bd970de9162c271: Scheduling FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e): perf score=10.126437
I20260812 06:18:15.743772 11240 maintenance_manager.cc:643] P 5f8119c610d94c448bd970de9162c271: FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e) complete. Timing: real 0.039s	user 0.012s	sys 0.023s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":18245,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:15.744313 11331 maintenance_manager.cc:419] P 5f8119c610d94c448bd970de9162c271: Scheduling FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e): perf score=2.188937
I20260812 06:18:15.761426 11240 maintenance_manager.cc:643] P 5f8119c610d94c448bd970de9162c271: FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e) complete. Timing: real 0.017s	user 0.016s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6453,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:15.761909 11331 maintenance_manager.cc:419] P 5f8119c610d94c448bd970de9162c271: Scheduling MajorDeltaCompactionOp(83f36c6eb02c4725b7837f77d761331e): perf score=1.000000
I20260812 06:18:15.887687 11240 maintenance_manager.cc:643] P 5f8119c610d94c448bd970de9162c271: MajorDeltaCompactionOp(83f36c6eb02c4725b7837f77d761331e) complete. Timing: real 0.126s	user 0.109s	sys 0.016s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672279,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":736,"lbm_read_time_us":10052,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25090,"lbm_writes_lt_1ms":443,"mutex_wait_us":65,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":14720,"update_count":2000}
I20260812 06:18:15.888410 11331 maintenance_manager.cc:419] P 5f8119c610d94c448bd970de9162c271: Scheduling FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e): perf score=10.126437
I20260812 06:18:15.930887 11240 maintenance_manager.cc:643] P 5f8119c610d94c448bd970de9162c271: FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e) complete. Timing: real 0.042s	user 0.028s	sys 0.012s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":19386,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":301,"reinsert_count":0,"update_count":1500}
I20260812 06:18:15.931456 11331 maintenance_manager.cc:419] P 5f8119c610d94c448bd970de9162c271: Scheduling FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e): perf score=2.188937
I20260812 06:18:15.948571 11240 maintenance_manager.cc:643] P 5f8119c610d94c448bd970de9162c271: FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e) complete. Timing: real 0.017s	user 0.010s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6405,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:15.949200 11331 maintenance_manager.cc:419] P 5f8119c610d94c448bd970de9162c271: Scheduling FlushMRSOp(83f36c6eb02c4725b7837f77d761331e): perf score=1.000000
I20260812 06:18:15.980341 11240 maintenance_manager.cc:643] P 5f8119c610d94c448bd970de9162c271: FlushMRSOp(83f36c6eb02c4725b7837f77d761331e) complete. Timing: real 0.031s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":68,"dirs.run_cpu_time_us":269,"dirs.run_wall_time_us":1371,"drs_written":1,"lbm_read_time_us":40,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1454,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:18:15.981175 11331 maintenance_manager.cc:419] P 5f8119c610d94c448bd970de9162c271: Scheduling LogGCOp(83f36c6eb02c4725b7837f77d761331e): free 121006393 bytes of WAL
I20260812 06:18:15.981415 11240 log_reader.cc:385] T 83f36c6eb02c4725b7837f77d761331e: removed 12 log segments from log reader
I20260812 06:18:15.981475 11240 log.cc:1079] T 83f36c6eb02c4725b7837f77d761331e P 5f8119c610d94c448bd970de9162c271: Deleting log segment in path: /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515494136637-11097-0/minicluster-data/ts-0-root/wals/83f36c6eb02c4725b7837f77d761331e/wal-000000003 (ops 11-15)
I20260812 06:18:15.981530 11240 log.cc:1079] T 83f36c6eb02c4725b7837f77d761331e P 5f8119c610d94c448bd970de9162c271: Deleting log segment in path: /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515494136637-11097-0/minicluster-data/ts-0-root/wals/83f36c6eb02c4725b7837f77d761331e/wal-000000004 (ops 16-20)
I20260812 06:18:15.981590 11240 log.cc:1079] T 83f36c6eb02c4725b7837f77d761331e P 5f8119c610d94c448bd970de9162c271: Deleting log segment in path: /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515494136637-11097-0/minicluster-data/ts-0-root/wals/83f36c6eb02c4725b7837f77d761331e/wal-000000005 (ops 21-25)
I20260812 06:18:15.981630 11240 log.cc:1079] T 83f36c6eb02c4725b7837f77d761331e P 5f8119c610d94c448bd970de9162c271: Deleting log segment in path: /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515494136637-11097-0/minicluster-data/ts-0-root/wals/83f36c6eb02c4725b7837f77d761331e/wal-000000006 (ops 26-30)
I20260812 06:18:15.981667 11240 log.cc:1079] T 83f36c6eb02c4725b7837f77d761331e P 5f8119c610d94c448bd970de9162c271: Deleting log segment in path: /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515494136637-11097-0/minicluster-data/ts-0-root/wals/83f36c6eb02c4725b7837f77d761331e/wal-000000007 (ops 31-35)
I20260812 06:18:15.981705 11240 log.cc:1079] T 83f36c6eb02c4725b7837f77d761331e P 5f8119c610d94c448bd970de9162c271: Deleting log segment in path: /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515494136637-11097-0/minicluster-data/ts-0-root/wals/83f36c6eb02c4725b7837f77d761331e/wal-000000008 (ops 36-40)
I20260812 06:18:15.981741 11240 log.cc:1079] T 83f36c6eb02c4725b7837f77d761331e P 5f8119c610d94c448bd970de9162c271: Deleting log segment in path: /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515494136637-11097-0/minicluster-data/ts-0-root/wals/83f36c6eb02c4725b7837f77d761331e/wal-000000009 (ops 41-45)
I20260812 06:18:15.981786 11240 log.cc:1079] T 83f36c6eb02c4725b7837f77d761331e P 5f8119c610d94c448bd970de9162c271: Deleting log segment in path: /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515494136637-11097-0/minicluster-data/ts-0-root/wals/83f36c6eb02c4725b7837f77d761331e/wal-000000010 (ops 46-50)
I20260812 06:18:15.981819 11240 log.cc:1079] T 83f36c6eb02c4725b7837f77d761331e P 5f8119c610d94c448bd970de9162c271: Deleting log segment in path: /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515494136637-11097-0/minicluster-data/ts-0-root/wals/83f36c6eb02c4725b7837f77d761331e/wal-000000011 (ops 51-55)
I20260812 06:18:15.981855 11240 log.cc:1079] T 83f36c6eb02c4725b7837f77d761331e P 5f8119c610d94c448bd970de9162c271: Deleting log segment in path: /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515494136637-11097-0/minicluster-data/ts-0-root/wals/83f36c6eb02c4725b7837f77d761331e/wal-000000012 (ops 56-60)
I20260812 06:18:15.981894 11240 log.cc:1079] T 83f36c6eb02c4725b7837f77d761331e P 5f8119c610d94c448bd970de9162c271: Deleting log segment in path: /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515494136637-11097-0/minicluster-data/ts-0-root/wals/83f36c6eb02c4725b7837f77d761331e/wal-000000013 (ops 61-64)
I20260812 06:18:15.981930 11240 log.cc:1079] T 83f36c6eb02c4725b7837f77d761331e P 5f8119c610d94c448bd970de9162c271: Deleting log segment in path: /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515494136637-11097-0/minicluster-data/ts-0-root/wals/83f36c6eb02c4725b7837f77d761331e/wal-000000014 (ops 65-69)
I20260812 06:18:16.011554 11240 maintenance_manager.cc:643] P 5f8119c610d94c448bd970de9162c271: LogGCOp(83f36c6eb02c4725b7837f77d761331e) complete. Timing: real 0.030s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:18:16.012092 11331 maintenance_manager.cc:419] P 5f8119c610d94c448bd970de9162c271: Scheduling FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e): perf score=3.181125
I20260812 06:18:16.025790 11240 maintenance_manager.cc:643] P 5f8119c610d94c448bd970de9162c271: FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e) complete. Timing: real 0.014s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4841098,"delete_count":0,"lbm_write_time_us":5243,"lbm_writes_lt_1ms":121,"reinsert_count":0,"update_count":590}
I20260812 06:18:16.026288 11331 maintenance_manager.cc:419] P 5f8119c610d94c448bd970de9162c271: Scheduling UndoDeltaBlockGCOp(83f36c6eb02c4725b7837f77d761331e): 472 bytes on disk
I20260812 06:18:16.026769 11240 maintenance_manager.cc:643] P 5f8119c610d94c448bd970de9162c271: UndoDeltaBlockGCOp(83f36c6eb02c4725b7837f77d761331e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":63,"lbm_reads_lt_1ms":4}
I20260812 06:18:16.027259 11331 maintenance_manager.cc:419] P 5f8119c610d94c448bd970de9162c271: Scheduling FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e): perf score=2.188937
I20260812 06:18:16.040432 11240 maintenance_manager.cc:643] P 5f8119c610d94c448bd970de9162c271: FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e) complete. Timing: real 0.013s	user 0.002s	sys 0.008s Metrics: {"bytes_written":3364205,"delete_count":0,"lbm_write_time_us":4739,"lbm_writes_lt_1ms":85,"reinsert_count":0,"update_count":410}
I20260812 06:18:16.041066 11331 maintenance_manager.cc:419] P 5f8119c610d94c448bd970de9162c271: Scheduling MajorDeltaCompactionOp(83f36c6eb02c4725b7837f77d761331e): perf score=1.000000
I20260812 06:18:16.203552 11240 maintenance_manager.cc:643] P 5f8119c610d94c448bd970de9162c271: MajorDeltaCompactionOp(83f36c6eb02c4725b7837f77d761331e) complete. Timing: real 0.162s	user 0.141s	sys 0.021s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877323,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":202,"lbm_read_time_us":11169,"lbm_reads_lt_1ms":674,"lbm_write_time_us":33187,"lbm_writes_lt_1ms":643,"mutex_wait_us":27,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":10112,"thread_start_us":76,"threads_started":1,"update_count":3000}
I20260812 06:18:16.204257 11331 maintenance_manager.cc:419] P 5f8119c610d94c448bd970de9162c271: Scheduling FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e): perf score=14.095187
I20260812 06:18:16.251252 11240 maintenance_manager.cc:643] P 5f8119c610d94c448bd970de9162c271: FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e) complete. Timing: real 0.047s	user 0.019s	sys 0.023s Metrics: {"bytes_written":16409898,"delete_count":0,"lbm_write_time_us":19740,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:16.251878 11331 maintenance_manager.cc:419] P 5f8119c610d94c448bd970de9162c271: Scheduling FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e): perf score=2.188937
I20260812 06:18:16.262396 11240 maintenance_manager.cc:643] P 5f8119c610d94c448bd970de9162c271: FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4096,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:16.262884 11331 maintenance_manager.cc:419] P 5f8119c610d94c448bd970de9162c271: Scheduling MajorDeltaCompactionOp(83f36c6eb02c4725b7837f77d761331e): perf score=1.000000
I20260812 06:18:16.429677 11240 maintenance_manager.cc:643] P 5f8119c610d94c448bd970de9162c271: MajorDeltaCompactionOp(83f36c6eb02c4725b7837f77d761331e) complete. Timing: real 0.167s	user 0.116s	sys 0.039s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774684,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":578,"lbm_read_time_us":11096,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30313,"lbm_writes_lt_1ms":543,"mutex_wait_us":50,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":82176,"update_count":2500}
I20260812 06:18:16.430250 11331 maintenance_manager.cc:419] P 5f8119c610d94c448bd970de9162c271: Scheduling FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e): perf score=14.095187
I20260812 06:18:16.472702 11240 maintenance_manager.cc:643] P 5f8119c610d94c448bd970de9162c271: FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e) complete. Timing: real 0.042s	user 0.023s	sys 0.016s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19146,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:16.473263 11331 maintenance_manager.cc:419] P 5f8119c610d94c448bd970de9162c271: Scheduling MajorDeltaCompactionOp(83f36c6eb02c4725b7837f77d761331e): perf score=1.000000
I20260812 06:18:16.620401 11240 maintenance_manager.cc:643] P 5f8119c610d94c448bd970de9162c271: MajorDeltaCompactionOp(83f36c6eb02c4725b7837f77d761331e) complete. Timing: real 0.147s	user 0.102s	sys 0.045s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672158,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":183,"lbm_read_time_us":9163,"lbm_reads_lt_1ms":467,"lbm_write_time_us":27301,"lbm_writes_lt_1ms":443,"mutex_wait_us":22,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11008,"update_count":2000}
I20260812 06:18:16.621069 11331 maintenance_manager.cc:419] P 5f8119c610d94c448bd970de9162c271: Scheduling FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e): perf score=10.126437
I20260812 06:18:16.661471 11240 maintenance_manager.cc:643] P 5f8119c610d94c448bd970de9162c271: FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e) complete. Timing: real 0.040s	user 0.031s	sys 0.008s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17535,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:18:16.661994 11331 maintenance_manager.cc:419] P 5f8119c610d94c448bd970de9162c271: Scheduling FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e): perf score=2.188937
I20260812 06:18:16.678776 11240 maintenance_manager.cc:643] P 5f8119c610d94c448bd970de9162c271: FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e) complete. Timing: real 0.017s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4867,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:16.679373 11331 maintenance_manager.cc:419] P 5f8119c610d94c448bd970de9162c271: Scheduling MajorDeltaCompactionOp(83f36c6eb02c4725b7837f77d761331e): perf score=1.000000
I20260812 06:18:16.805045 11240 maintenance_manager.cc:643] P 5f8119c610d94c448bd970de9162c271: MajorDeltaCompactionOp(83f36c6eb02c4725b7837f77d761331e) complete. Timing: real 0.125s	user 0.097s	sys 0.027s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":194,"lbm_read_time_us":7657,"lbm_reads_lt_1ms":464,"lbm_write_time_us":23372,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:18:16.805876 11331 maintenance_manager.cc:419] P 5f8119c610d94c448bd970de9162c271: Scheduling FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e): perf score=11.118625
I20260812 06:18:16.848016 11240 maintenance_manager.cc:643] P 5f8119c610d94c448bd970de9162c271: FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e) complete. Timing: real 0.042s	user 0.020s	sys 0.020s Metrics: {"bytes_written":12430562,"delete_count":0,"lbm_write_time_us":18929,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":305,"reinsert_count":0,"update_count":1515}
I20260812 06:18:16.848582 11331 maintenance_manager.cc:419] P 5f8119c610d94c448bd970de9162c271: Scheduling FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e): perf score=2.188937
I20260812 06:18:16.866401 11240 maintenance_manager.cc:643] P 5f8119c610d94c448bd970de9162c271: FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e) complete. Timing: real 0.018s	user 0.010s	sys 0.001s Metrics: {"bytes_written":3979584,"delete_count":0,"lbm_write_time_us":4756,"lbm_writes_lt_1ms":100,"reinsert_count":0,"update_count":485}
I20260812 06:18:16.866919 11331 maintenance_manager.cc:419] P 5f8119c610d94c448bd970de9162c271: Scheduling MajorDeltaCompactionOp(83f36c6eb02c4725b7837f77d761331e): perf score=1.000000
I20260812 06:18:16.984870 11240 maintenance_manager.cc:643] P 5f8119c610d94c448bd970de9162c271: MajorDeltaCompactionOp(83f36c6eb02c4725b7837f77d761331e) complete. Timing: real 0.118s	user 0.101s	sys 0.014s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672274,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1015,"lbm_read_time_us":7571,"lbm_reads_lt_1ms":464,"lbm_write_time_us":24012,"lbm_writes_lt_1ms":443,"mutex_wait_us":303,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":2816,"update_count":2000}
I20260812 06:18:16.985632 11331 maintenance_manager.cc:419] P 5f8119c610d94c448bd970de9162c271: Scheduling FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e): perf score=11.118625
I20260812 06:18:17.026054 11240 maintenance_manager.cc:643] P 5f8119c610d94c448bd970de9162c271: FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e) complete. Timing: real 0.040s	user 0.021s	sys 0.017s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":16816,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:17.026697 11331 maintenance_manager.cc:419] P 5f8119c610d94c448bd970de9162c271: Scheduling FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e): perf score=2.188937
I20260812 06:18:17.045749 11240 maintenance_manager.cc:643] P 5f8119c610d94c448bd970de9162c271: FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e) complete. Timing: real 0.019s	user 0.007s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4350,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:17.046279 11331 maintenance_manager.cc:419] P 5f8119c610d94c448bd970de9162c271: Scheduling FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e): perf score=2.188937
I20260812 06:18:17.055925 11240 maintenance_manager.cc:643] P 5f8119c610d94c448bd970de9162c271: FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3667,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:17.056466 11331 maintenance_manager.cc:419] P 5f8119c610d94c448bd970de9162c271: Scheduling MajorDeltaCompactionOp(83f36c6eb02c4725b7837f77d761331e): perf score=1.000000
I20260812 06:18:17.218025 11240 maintenance_manager.cc:643] P 5f8119c610d94c448bd970de9162c271: MajorDeltaCompactionOp(83f36c6eb02c4725b7837f77d761331e) complete. Timing: real 0.161s	user 0.105s	sys 0.055s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774798,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":207,"lbm_read_time_us":11332,"lbm_reads_lt_1ms":573,"lbm_write_time_us":32092,"lbm_writes_lt_1ms":543,"mutex_wait_us":70,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":15616,"update_count":2500}
I20260812 06:18:17.218895 11331 maintenance_manager.cc:419] P 5f8119c610d94c448bd970de9162c271: Scheduling FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e): perf score=12.110812
I20260812 06:18:17.266842 11240 maintenance_manager.cc:643] P 5f8119c610d94c448bd970de9162c271: FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e) complete. Timing: real 0.048s	user 0.030s	sys 0.016s Metrics: {"bytes_written":14276637,"delete_count":0,"lbm_write_time_us":20820,"lbm_writes_lt_1ms":351,"reinsert_count":0,"update_count":1740}
I20260812 06:18:17.267333 11331 maintenance_manager.cc:419] P 5f8119c610d94c448bd970de9162c271: Scheduling FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e): perf score=1.000000
I20260812 06:18:17.284652 11240 maintenance_manager.cc:643] P 5f8119c610d94c448bd970de9162c271: FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e) complete. Timing: real 0.017s	user 0.006s	sys 0.000s Metrics: {"bytes_written":2133453,"delete_count":0,"lbm_write_time_us":2612,"lbm_writes_lt_1ms":55,"reinsert_count":0,"update_count":260}
I20260812 06:18:17.285425 11331 maintenance_manager.cc:419] P 5f8119c610d94c448bd970de9162c271: Scheduling FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e): perf score=2.188937
I20260812 06:18:17.295776 11240 maintenance_manager.cc:643] P 5f8119c610d94c448bd970de9162c271: FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e) complete. Timing: real 0.010s	user 0.001s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3992,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:17.296243 11331 maintenance_manager.cc:419] P 5f8119c610d94c448bd970de9162c271: Scheduling FlushMRSOp(83f36c6eb02c4725b7837f77d761331e): perf score=1.000000
I20260812 06:18:17.328845 11240 maintenance_manager.cc:643] P 5f8119c610d94c448bd970de9162c271: FlushMRSOp(83f36c6eb02c4725b7837f77d761331e) complete. Timing: real 0.032s	user 0.026s	sys 0.004s Metrics: {"bytes_written":1152514,"cfile_init":1,"dirs.queue_time_us":66,"dirs.run_cpu_time_us":260,"dirs.run_wall_time_us":1608,"drs_written":1,"lbm_read_time_us":38,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1582,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:17.329663 11331 maintenance_manager.cc:419] P 5f8119c610d94c448bd970de9162c271: Scheduling LogGCOp(83f36c6eb02c4725b7837f77d761331e): free 112239383 bytes of WAL
I20260812 06:18:17.329911 11240 log_reader.cc:385] T 83f36c6eb02c4725b7837f77d761331e: removed 11 log segments from log reader
I20260812 06:18:17.329977 11240 log.cc:1079] T 83f36c6eb02c4725b7837f77d761331e P 5f8119c610d94c448bd970de9162c271: Deleting log segment in path: /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515494136637-11097-0/minicluster-data/ts-0-root/wals/83f36c6eb02c4725b7837f77d761331e/wal-000000015 (ops 70-74)
I20260812 06:18:17.330034 11240 log.cc:1079] T 83f36c6eb02c4725b7837f77d761331e P 5f8119c610d94c448bd970de9162c271: Deleting log segment in path: /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515494136637-11097-0/minicluster-data/ts-0-root/wals/83f36c6eb02c4725b7837f77d761331e/wal-000000016 (ops 75-79)
I20260812 06:18:17.330058 11240 log.cc:1079] T 83f36c6eb02c4725b7837f77d761331e P 5f8119c610d94c448bd970de9162c271: Deleting log segment in path: /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515494136637-11097-0/minicluster-data/ts-0-root/wals/83f36c6eb02c4725b7837f77d761331e/wal-000000017 (ops 80-84)
I20260812 06:18:17.330096 11240 log.cc:1079] T 83f36c6eb02c4725b7837f77d761331e P 5f8119c610d94c448bd970de9162c271: Deleting log segment in path: /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515494136637-11097-0/minicluster-data/ts-0-root/wals/83f36c6eb02c4725b7837f77d761331e/wal-000000018 (ops 85-89)
I20260812 06:18:17.330130 11240 log.cc:1079] T 83f36c6eb02c4725b7837f77d761331e P 5f8119c610d94c448bd970de9162c271: Deleting log segment in path: /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515494136637-11097-0/minicluster-data/ts-0-root/wals/83f36c6eb02c4725b7837f77d761331e/wal-000000019 (ops 90-94)
I20260812 06:18:17.330165 11240 log.cc:1079] T 83f36c6eb02c4725b7837f77d761331e P 5f8119c610d94c448bd970de9162c271: Deleting log segment in path: /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515494136637-11097-0/minicluster-data/ts-0-root/wals/83f36c6eb02c4725b7837f77d761331e/wal-000000020 (ops 95-99)
I20260812 06:18:17.330188 11240 log.cc:1079] T 83f36c6eb02c4725b7837f77d761331e P 5f8119c610d94c448bd970de9162c271: Deleting log segment in path: /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515494136637-11097-0/minicluster-data/ts-0-root/wals/83f36c6eb02c4725b7837f77d761331e/wal-000000021 (ops 100-104)
I20260812 06:18:17.330210 11240 log.cc:1079] T 83f36c6eb02c4725b7837f77d761331e P 5f8119c610d94c448bd970de9162c271: Deleting log segment in path: /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515494136637-11097-0/minicluster-data/ts-0-root/wals/83f36c6eb02c4725b7837f77d761331e/wal-000000022 (ops 105-108)
I20260812 06:18:17.330240 11240 log.cc:1079] T 83f36c6eb02c4725b7837f77d761331e P 5f8119c610d94c448bd970de9162c271: Deleting log segment in path: /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515494136637-11097-0/minicluster-data/ts-0-root/wals/83f36c6eb02c4725b7837f77d761331e/wal-000000023 (ops 109-113)
I20260812 06:18:17.330271 11240 log.cc:1079] T 83f36c6eb02c4725b7837f77d761331e P 5f8119c610d94c448bd970de9162c271: Deleting log segment in path: /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515494136637-11097-0/minicluster-data/ts-0-root/wals/83f36c6eb02c4725b7837f77d761331e/wal-000000024 (ops 114-118)
I20260812 06:18:17.330304 11240 log.cc:1079] T 83f36c6eb02c4725b7837f77d761331e P 5f8119c610d94c448bd970de9162c271: Deleting log segment in path: /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515494136637-11097-0/minicluster-data/ts-0-root/wals/83f36c6eb02c4725b7837f77d761331e/wal-000000025 (ops 119-123)
I20260812 06:18:17.359906 11240 maintenance_manager.cc:643] P 5f8119c610d94c448bd970de9162c271: LogGCOp(83f36c6eb02c4725b7837f77d761331e) complete. Timing: real 0.030s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:18:17.360482 11331 maintenance_manager.cc:419] P 5f8119c610d94c448bd970de9162c271: Scheduling FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e): perf score=2.188937
I20260812 06:18:17.386319 11240 maintenance_manager.cc:643] P 5f8119c610d94c448bd970de9162c271: FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e) complete. Timing: real 0.026s	user 0.006s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5675,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:17.386992 11331 maintenance_manager.cc:419] P 5f8119c610d94c448bd970de9162c271: Scheduling LogGCOp(83f36c6eb02c4725b7837f77d761331e): free 12017940 bytes of WAL
I20260812 06:18:17.387229 11240 log_reader.cc:385] T 83f36c6eb02c4725b7837f77d761331e: removed 1 log segments from log reader
I20260812 06:18:17.387293 11240 log.cc:1079] T 83f36c6eb02c4725b7837f77d761331e P 5f8119c610d94c448bd970de9162c271: Deleting log segment in path: /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515494136637-11097-0/minicluster-data/ts-0-root/wals/83f36c6eb02c4725b7837f77d761331e/wal-000000026 (ops 124-128)
I20260812 06:18:17.390336 11240 maintenance_manager.cc:643] P 5f8119c610d94c448bd970de9162c271: LogGCOp(83f36c6eb02c4725b7837f77d761331e) complete. Timing: real 0.003s	user 0.000s	sys 0.002s Metrics: {}
I20260812 06:18:17.390672 11331 maintenance_manager.cc:419] P 5f8119c610d94c448bd970de9162c271: Scheduling FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e): perf score=2.188937
I20260812 06:18:17.405468 11240 maintenance_manager.cc:643] P 5f8119c610d94c448bd970de9162c271: FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e) complete. Timing: real 0.015s	user 0.006s	sys 0.008s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5633,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:17.405910 11331 maintenance_manager.cc:419] P 5f8119c610d94c448bd970de9162c271: Scheduling MajorDeltaCompactionOp(83f36c6eb02c4725b7837f77d761331e): perf score=1.000000
I20260812 06:18:17.606142 11240 maintenance_manager.cc:643] P 5f8119c610d94c448bd970de9162c271: MajorDeltaCompactionOp(83f36c6eb02c4725b7837f77d761331e) complete. Timing: real 0.200s	user 0.140s	sys 0.060s Metrics: {"cfile_cache_miss":735,"cfile_cache_miss_bytes":32979808,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":5,"delta_iterators_relevant":5,"dirs.queue_time_us":563,"lbm_read_time_us":14511,"lbm_reads_lt_1ms":775,"lbm_write_time_us":38375,"lbm_writes_lt_1ms":743,"mutex_wait_us":49,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":1408,"thread_start_us":80,"threads_started":1,"update_count":3500}
I20260812 06:18:17.607553 11331 maintenance_manager.cc:419] P 5f8119c610d94c448bd970de9162c271: Scheduling UndoDeltaBlockGCOp(83f36c6eb02c4725b7837f77d761331e): 447 bytes on disk
I20260812 06:18:17.608144 11240 maintenance_manager.cc:643] P 5f8119c610d94c448bd970de9162c271: UndoDeltaBlockGCOp(83f36c6eb02c4725b7837f77d761331e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":98,"lbm_reads_lt_1ms":4}
I20260812 06:18:17.609584 11331 maintenance_manager.cc:419] P 5f8119c610d94c448bd970de9162c271: Scheduling FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e): perf score=14.095187
I20260812 06:18:17.662271 11240 maintenance_manager.cc:643] P 5f8119c610d94c448bd970de9162c271: FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e) complete. Timing: real 0.052s	user 0.030s	sys 0.013s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19164,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:17.662990 11331 maintenance_manager.cc:419] P 5f8119c610d94c448bd970de9162c271: Scheduling FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e): perf score=2.188937
I20260812 06:18:17.678083 11240 maintenance_manager.cc:643] P 5f8119c610d94c448bd970de9162c271: FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e) complete. Timing: real 0.015s	user 0.001s	sys 0.011s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4947,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:17.678514 11331 maintenance_manager.cc:419] P 5f8119c610d94c448bd970de9162c271: Scheduling FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e): perf score=2.188937
I20260812 06:18:17.689065 11240 maintenance_manager.cc:643] P 5f8119c610d94c448bd970de9162c271: FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4003,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:17.689477 11331 maintenance_manager.cc:419] P 5f8119c610d94c448bd970de9162c271: Scheduling MajorDeltaCompactionOp(83f36c6eb02c4725b7837f77d761331e): perf score=1.000000
I20260812 06:18:17.854444 11240 maintenance_manager.cc:643] P 5f8119c610d94c448bd970de9162c271: MajorDeltaCompactionOp(83f36c6eb02c4725b7837f77d761331e) complete. Timing: real 0.165s	user 0.124s	sys 0.040s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877219,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1148,"lbm_read_time_us":12344,"lbm_reads_lt_1ms":673,"lbm_write_time_us":35051,"lbm_writes_lt_1ms":643,"mutex_wait_us":368,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":4352,"update_count":3000}
I20260812 06:18:17.855144 11331 maintenance_manager.cc:419] P 5f8119c610d94c448bd970de9162c271: Scheduling FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e): perf score=14.095187
I20260812 06:18:17.903298 11240 maintenance_manager.cc:643] P 5f8119c610d94c448bd970de9162c271: FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e) complete. Timing: real 0.048s	user 0.033s	sys 0.012s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":20922,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:17.903857 11331 maintenance_manager.cc:419] P 5f8119c610d94c448bd970de9162c271: Scheduling FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e): perf score=2.188937
I20260812 06:18:17.920128 11240 maintenance_manager.cc:643] P 5f8119c610d94c448bd970de9162c271: FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e) complete. Timing: real 0.016s	user 0.007s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6494,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:17.920905 11331 maintenance_manager.cc:419] P 5f8119c610d94c448bd970de9162c271: Scheduling MajorDeltaCompactionOp(83f36c6eb02c4725b7837f77d761331e): perf score=1.000000
I20260812 06:18:18.085299 11240 maintenance_manager.cc:643] P 5f8119c610d94c448bd970de9162c271: MajorDeltaCompactionOp(83f36c6eb02c4725b7837f77d761331e) complete. Timing: real 0.164s	user 0.097s	sys 0.062s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":6650,"lbm_read_time_us":11604,"lbm_reads_lt_1ms":564,"lbm_write_time_us":32547,"lbm_writes_lt_1ms":543,"mutex_wait_us":3062,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2500}
I20260812 06:18:18.086130 11331 maintenance_manager.cc:419] P 5f8119c610d94c448bd970de9162c271: Scheduling FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e): perf score=11.118625
I20260812 06:18:18.131090 11240 maintenance_manager.cc:643] P 5f8119c610d94c448bd970de9162c271: FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e) complete. Timing: real 0.045s	user 0.021s	sys 0.013s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":15540,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:18:18.131727 11331 maintenance_manager.cc:419] P 5f8119c610d94c448bd970de9162c271: Scheduling FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e): perf score=2.188937
I20260812 06:18:18.155404 11240 maintenance_manager.cc:643] P 5f8119c610d94c448bd970de9162c271: FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e) complete. Timing: real 0.023s	user 0.007s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4708,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:18.155877 11331 maintenance_manager.cc:419] P 5f8119c610d94c448bd970de9162c271: Scheduling FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e): perf score=2.188937
I20260812 06:18:18.166265 11240 maintenance_manager.cc:643] P 5f8119c610d94c448bd970de9162c271: FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e) complete. Timing: real 0.010s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3941,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:18.166724 11331 maintenance_manager.cc:419] P 5f8119c610d94c448bd970de9162c271: Scheduling MajorDeltaCompactionOp(83f36c6eb02c4725b7837f77d761331e): perf score=1.000000
I20260812 06:18:18.341977 11240 maintenance_manager.cc:643] P 5f8119c610d94c448bd970de9162c271: MajorDeltaCompactionOp(83f36c6eb02c4725b7837f77d761331e) complete. Timing: real 0.175s	user 0.130s	sys 0.040s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774800,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":753,"lbm_read_time_us":13267,"lbm_reads_lt_1ms":573,"lbm_write_time_us":29431,"lbm_writes_lt_1ms":543,"mutex_wait_us":1,"peak_mem_usage":63115900,"reinsert_count":0,"update_count":2500}
I20260812 06:18:18.342689 11331 maintenance_manager.cc:419] P 5f8119c610d94c448bd970de9162c271: Scheduling FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e): perf score=14.095187
I20260812 06:18:18.412081 11240 maintenance_manager.cc:643] P 5f8119c610d94c448bd970de9162c271: FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e) complete. Timing: real 0.069s	user 0.041s	sys 0.024s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":32852,"lbm_writes_1-10_ms":3,"lbm_writes_lt_1ms":400,"reinsert_count":0,"update_count":2000}
I20260812 06:18:18.412711 11331 maintenance_manager.cc:419] P 5f8119c610d94c448bd970de9162c271: Scheduling FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e): perf score=2.188937
I20260812 06:18:18.423229 11240 maintenance_manager.cc:643] P 5f8119c610d94c448bd970de9162c271: FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3976,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:18.423770 11331 maintenance_manager.cc:419] P 5f8119c610d94c448bd970de9162c271: Scheduling MajorDeltaCompactionOp(83f36c6eb02c4725b7837f77d761331e): perf score=1.000000
I20260812 06:18:18.599749 11240 maintenance_manager.cc:643] P 5f8119c610d94c448bd970de9162c271: MajorDeltaCompactionOp(83f36c6eb02c4725b7837f77d761331e) complete. Timing: real 0.176s	user 0.122s	sys 0.049s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774691,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":299,"lbm_read_time_us":13013,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29524,"lbm_writes_lt_1ms":543,"mutex_wait_us":2,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":2500}
I20260812 06:18:18.604082 11331 maintenance_manager.cc:419] P 5f8119c610d94c448bd970de9162c271: Scheduling FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e): perf score=14.095187
I20260812 06:18:18.663019 11240 maintenance_manager.cc:643] P 5f8119c610d94c448bd970de9162c271: FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e) complete. Timing: real 0.059s	user 0.033s	sys 0.023s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22398,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:18.663583 11331 maintenance_manager.cc:419] P 5f8119c610d94c448bd970de9162c271: Scheduling FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e): perf score=2.188937
I20260812 06:18:18.674283 11240 maintenance_manager.cc:643] P 5f8119c610d94c448bd970de9162c271: FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4087,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:18.674721 11331 maintenance_manager.cc:419] P 5f8119c610d94c448bd970de9162c271: Scheduling FlushMRSOp(83f36c6eb02c4725b7837f77d761331e): perf score=1.000000
I20260812 06:18:18.714619 11240 maintenance_manager.cc:643] P 5f8119c610d94c448bd970de9162c271: FlushMRSOp(83f36c6eb02c4725b7837f77d761331e) complete. Timing: real 0.040s	user 0.025s	sys 0.003s Metrics: {"bytes_written":1152510,"cfile_init":1,"dirs.queue_time_us":51,"dirs.run_cpu_time_us":185,"dirs.run_wall_time_us":1336,"drs_written":1,"lbm_read_time_us":59,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1393,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:18.715360 11331 maintenance_manager.cc:419] P 5f8119c610d94c448bd970de9162c271: Scheduling LogGCOp(83f36c6eb02c4725b7837f77d761331e): free 108535630 bytes of WAL
I20260812 06:18:18.715613 11240 log_reader.cc:385] T 83f36c6eb02c4725b7837f77d761331e: removed 11 log segments from log reader
I20260812 06:18:18.715660 11240 log.cc:1079] T 83f36c6eb02c4725b7837f77d761331e P 5f8119c610d94c448bd970de9162c271: Deleting log segment in path: /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515494136637-11097-0/minicluster-data/ts-0-root/wals/83f36c6eb02c4725b7837f77d761331e/wal-000000027 (ops 129-133)
I20260812 06:18:18.715690 11240 log.cc:1079] T 83f36c6eb02c4725b7837f77d761331e P 5f8119c610d94c448bd970de9162c271: Deleting log segment in path: /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515494136637-11097-0/minicluster-data/ts-0-root/wals/83f36c6eb02c4725b7837f77d761331e/wal-000000028 (ops 134-138)
I20260812 06:18:18.715713 11240 log.cc:1079] T 83f36c6eb02c4725b7837f77d761331e P 5f8119c610d94c448bd970de9162c271: Deleting log segment in path: /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515494136637-11097-0/minicluster-data/ts-0-root/wals/83f36c6eb02c4725b7837f77d761331e/wal-000000029 (ops 139-142)
I20260812 06:18:18.716004 11240 log.cc:1079] T 83f36c6eb02c4725b7837f77d761331e P 5f8119c610d94c448bd970de9162c271: Deleting log segment in path: /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515494136637-11097-0/minicluster-data/ts-0-root/wals/83f36c6eb02c4725b7837f77d761331e/wal-000000030 (ops 143-147)
I20260812 06:18:18.716063 11240 log.cc:1079] T 83f36c6eb02c4725b7837f77d761331e P 5f8119c610d94c448bd970de9162c271: Deleting log segment in path: /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515494136637-11097-0/minicluster-data/ts-0-root/wals/83f36c6eb02c4725b7837f77d761331e/wal-000000031 (ops 148-152)
I20260812 06:18:18.716106 11240 log.cc:1079] T 83f36c6eb02c4725b7837f77d761331e P 5f8119c610d94c448bd970de9162c271: Deleting log segment in path: /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515494136637-11097-0/minicluster-data/ts-0-root/wals/83f36c6eb02c4725b7837f77d761331e/wal-000000032 (ops 153-157)
I20260812 06:18:18.716154 11240 log.cc:1079] T 83f36c6eb02c4725b7837f77d761331e P 5f8119c610d94c448bd970de9162c271: Deleting log segment in path: /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515494136637-11097-0/minicluster-data/ts-0-root/wals/83f36c6eb02c4725b7837f77d761331e/wal-000000033 (ops 158-162)
I20260812 06:18:18.716194 11240 log.cc:1079] T 83f36c6eb02c4725b7837f77d761331e P 5f8119c610d94c448bd970de9162c271: Deleting log segment in path: /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515494136637-11097-0/minicluster-data/ts-0-root/wals/83f36c6eb02c4725b7837f77d761331e/wal-000000034 (ops 163-166)
I20260812 06:18:18.716230 11240 log.cc:1079] T 83f36c6eb02c4725b7837f77d761331e P 5f8119c610d94c448bd970de9162c271: Deleting log segment in path: /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515494136637-11097-0/minicluster-data/ts-0-root/wals/83f36c6eb02c4725b7837f77d761331e/wal-000000035 (ops 167-171)
I20260812 06:18:18.716271 11240 log.cc:1079] T 83f36c6eb02c4725b7837f77d761331e P 5f8119c610d94c448bd970de9162c271: Deleting log segment in path: /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515494136637-11097-0/minicluster-data/ts-0-root/wals/83f36c6eb02c4725b7837f77d761331e/wal-000000036 (ops 172-176)
I20260812 06:18:18.716310 11240 log.cc:1079] T 83f36c6eb02c4725b7837f77d761331e P 5f8119c610d94c448bd970de9162c271: Deleting log segment in path: /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515494136637-11097-0/minicluster-data/ts-0-root/wals/83f36c6eb02c4725b7837f77d761331e/wal-000000037 (ops 177-181)
I20260812 06:18:18.740267 11240 maintenance_manager.cc:643] P 5f8119c610d94c448bd970de9162c271: LogGCOp(83f36c6eb02c4725b7837f77d761331e) complete. Timing: real 0.025s	user 0.000s	sys 0.021s Metrics: {}
I20260812 06:18:18.740795 11331 maintenance_manager.cc:419] P 5f8119c610d94c448bd970de9162c271: Scheduling FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e): perf score=2.188937
I20260812 06:18:18.759328 11240 maintenance_manager.cc:643] P 5f8119c610d94c448bd970de9162c271: FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e) complete. Timing: real 0.018s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4344,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:18.759877 11331 maintenance_manager.cc:419] P 5f8119c610d94c448bd970de9162c271: Scheduling UndoDeltaBlockGCOp(83f36c6eb02c4725b7837f77d761331e): 447 bytes on disk
I20260812 06:18:18.760352 11240 maintenance_manager.cc:643] P 5f8119c610d94c448bd970de9162c271: UndoDeltaBlockGCOp(83f36c6eb02c4725b7837f77d761331e) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":56,"lbm_reads_lt_1ms":4}
I20260812 06:18:18.760996 11331 maintenance_manager.cc:419] P 5f8119c610d94c448bd970de9162c271: Scheduling FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e): perf score=2.188937
I20260812 06:18:18.772114 11240 maintenance_manager.cc:643] P 5f8119c610d94c448bd970de9162c271: FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4115,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:18.772950 11331 maintenance_manager.cc:419] P 5f8119c610d94c448bd970de9162c271: Scheduling MajorDeltaCompactionOp(83f36c6eb02c4725b7837f77d761331e): perf score=1.000000
I20260812 06:18:19.011593 11240 maintenance_manager.cc:643] P 5f8119c610d94c448bd970de9162c271: MajorDeltaCompactionOp(83f36c6eb02c4725b7837f77d761331e) complete. Timing: real 0.238s	user 0.170s	sys 0.064s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979750,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":1849,"lbm_read_time_us":17022,"lbm_reads_lt_1ms":774,"lbm_write_time_us":45256,"lbm_writes_lt_1ms":743,"mutex_wait_us":1560,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":30080,"thread_start_us":77,"threads_started":1,"update_count":3500}
I20260812 06:18:19.012331 11331 maintenance_manager.cc:419] P 5f8119c610d94c448bd970de9162c271: Scheduling FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e): perf score=15.087375
I20260812 06:18:19.073104 11240 maintenance_manager.cc:643] P 5f8119c610d94c448bd970de9162c271: FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e) complete. Timing: real 0.061s	user 0.046s	sys 0.007s Metrics: {"bytes_written":16820142,"delete_count":0,"lbm_write_time_us":23447,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:18:19.073788 11331 maintenance_manager.cc:419] P 5f8119c610d94c448bd970de9162c271: Scheduling FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e): perf score=6.157687
I20260812 06:18:19.107587 11240 maintenance_manager.cc:643] P 5f8119c610d94c448bd970de9162c271: FlushDeltaMemStoresOp(83f36c6eb02c4725b7837f77d761331e) complete. Timing: real 0.034s	user 0.016s	sys 0.008s Metrics: {"bytes_written":7794836,"delete_count":0,"lbm_write_time_us":11582,"lbm_writes_lt_1ms":193,"reinsert_count":0,"update_count":950}
I20260812 06:18:19.108099 11331 maintenance_manager.cc:419] P 5f8119c610d94c448bd970de9162c271: Scheduling MajorDeltaCompactionOp(83f36c6eb02c4725b7837f77d761331e): perf score=1.000000
I20260812 06:18:19.164014 11097 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.768s	user 1.776s	sys 0.180s
I20260812 06:18:19.242350 11097 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.078s	user 0.002s	sys 0.000s
I20260812 06:18:19.243011 11097 tablet_server.cc:179] TabletServer@127.10.214.65:0 shutting down...
I20260812 06:18:19.270478 11240 maintenance_manager.cc:643] P 5f8119c610d94c448bd970de9162c271: MajorDeltaCompactionOp(83f36c6eb02c4725b7837f77d761331e) complete. Timing: real 0.162s	user 0.126s	sys 0.036s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28877100,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":252,"lbm_read_time_us":12235,"lbm_reads_lt_1ms":660,"lbm_write_time_us":33283,"lbm_writes_lt_1ms":643,"mutex_wait_us":34,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":3000}
I20260812 06:18:19.271550 11097 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:19.271930 11097 tablet_replica.cc:333] T 83f36c6eb02c4725b7837f77d761331e P 5f8119c610d94c448bd970de9162c271: stopping tablet replica
I20260812 06:18:19.272197 11097 raft_consensus.cc:2243] T 83f36c6eb02c4725b7837f77d761331e P 5f8119c610d94c448bd970de9162c271 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:19.272440 11097 raft_consensus.cc:2272] T 83f36c6eb02c4725b7837f77d761331e P 5f8119c610d94c448bd970de9162c271 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:19.289609 11097 tablet_server.cc:196] TabletServer@127.10.214.65:0 shutdown complete.
I20260812 06:18:19.323980 11097 master.cc:562] Master@127.10.214.126:46093 shutting down...
I20260812 06:18:19.328217 11097 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 301bfd7d44154c0e953fa9734d12d18c [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:19.328423 11097 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 301bfd7d44154c0e953fa9734d12d18c [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:19.328510 11097 tablet_replica.cc:333] T 00000000000000000000000000000000 P 301bfd7d44154c0e953fa9734d12d18c: stopping tablet replica
I20260812 06:18:19.341089 11097 master.cc:584] Master@127.10.214.126:46093 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5286 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:18:19.434100 11097 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.10.214.126:46599
I20260812 06:18:19.434527 11097 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:19.436784 11380 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:19.436884 11381 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:19.436942 11097 server_base.cc:1061] running on GCE node
W20260812 06:18:19.436744 11384 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:19.437193 11097 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:19.437242 11097 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:19.437264 11097 hybrid_clock.cc:648] HybridClock initialized: now 1786515499437264 us; error 0 us; skew 500 ppm
I20260812 06:18:19.438151 11097 webserver.cc:533] Webserver started at http://127.10.214.126:42723/ using document root <none> and password file <none>
I20260812 06:18:19.438335 11097 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:19.438380 11097 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:19.438478 11097 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:19.438851 11097 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515494136637-11097-0/minicluster-data/master-0-root/instance:
uuid: "8f2686ee72bf433493870404e6fe313d"
format_stamp: "Formatted at 2026-08-12 06:18:19 on dist-test-slave-x5fp"
I20260812 06:18:19.440289 11097 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:18:19.441337 11394 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:19.441578 11097 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.000s
I20260812 06:18:19.441663 11097 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515494136637-11097-0/minicluster-data/master-0-root
uuid: "8f2686ee72bf433493870404e6fe313d"
format_stamp: "Formatted at 2026-08-12 06:18:19 on dist-test-slave-x5fp"
I20260812 06:18:19.441744 11097 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515494136637-11097-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515494136637-11097-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515494136637-11097-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:19.460532 11097 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:19.461006 11097 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:19.465139 11097 rpc_server.cc:307] RPC server started. Bound to: 127.10.214.126:46599
I20260812 06:18:19.467741 11468 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.10.214.126:46599 every 8 connection(s)
I20260812 06:18:19.468744 11469 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:19.479139 11469 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 8f2686ee72bf433493870404e6fe313d: Bootstrap starting.
I20260812 06:18:19.485299 11469 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 8f2686ee72bf433493870404e6fe313d: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:19.486411 11469 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 8f2686ee72bf433493870404e6fe313d: No bootstrap required, opened a new log
I20260812 06:18:19.486799 11469 raft_consensus.cc:359] T 00000000000000000000000000000000 P 8f2686ee72bf433493870404e6fe313d [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8f2686ee72bf433493870404e6fe313d" member_type: VOTER }
I20260812 06:18:19.486888 11469 raft_consensus.cc:385] T 00000000000000000000000000000000 P 8f2686ee72bf433493870404e6fe313d [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:19.486912 11469 raft_consensus.cc:740] T 00000000000000000000000000000000 P 8f2686ee72bf433493870404e6fe313d [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 8f2686ee72bf433493870404e6fe313d, State: Initialized, Role: FOLLOWER
I20260812 06:18:19.487066 11469 consensus_queue.cc:260] T 00000000000000000000000000000000 P 8f2686ee72bf433493870404e6fe313d [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: "8f2686ee72bf433493870404e6fe313d" member_type: VOTER }
I20260812 06:18:19.487154 11469 raft_consensus.cc:399] T 00000000000000000000000000000000 P 8f2686ee72bf433493870404e6fe313d [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:19.487179 11469 raft_consensus.cc:493] T 00000000000000000000000000000000 P 8f2686ee72bf433493870404e6fe313d [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:19.487216 11469 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 8f2686ee72bf433493870404e6fe313d [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:19.487890 11469 raft_consensus.cc:515] T 00000000000000000000000000000000 P 8f2686ee72bf433493870404e6fe313d [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8f2686ee72bf433493870404e6fe313d" member_type: VOTER }
I20260812 06:18:19.487999 11469 leader_election.cc:304] T 00000000000000000000000000000000 P 8f2686ee72bf433493870404e6fe313d [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: 8f2686ee72bf433493870404e6fe313d; no voters: 
I20260812 06:18:19.488152 11469 leader_election.cc:290] T 00000000000000000000000000000000 P 8f2686ee72bf433493870404e6fe313d [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:19.488289 11473 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 8f2686ee72bf433493870404e6fe313d [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:19.488509 11473 raft_consensus.cc:697] T 00000000000000000000000000000000 P 8f2686ee72bf433493870404e6fe313d [term 1 LEADER]: Becoming Leader. State: Replica: 8f2686ee72bf433493870404e6fe313d, State: Running, Role: LEADER
I20260812 06:18:19.488607 11469 sys_catalog.cc:565] T 00000000000000000000000000000000 P 8f2686ee72bf433493870404e6fe313d [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:18:19.488657 11473 consensus_queue.cc:237] T 00000000000000000000000000000000 P 8f2686ee72bf433493870404e6fe313d [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: "8f2686ee72bf433493870404e6fe313d" member_type: VOTER }
I20260812 06:18:19.489130 11474 sys_catalog.cc:455] T 00000000000000000000000000000000 P 8f2686ee72bf433493870404e6fe313d [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "8f2686ee72bf433493870404e6fe313d" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8f2686ee72bf433493870404e6fe313d" member_type: VOTER } }
I20260812 06:18:19.489238 11474 sys_catalog.cc:458] T 00000000000000000000000000000000 P 8f2686ee72bf433493870404e6fe313d [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:19.489146 11475 sys_catalog.cc:455] T 00000000000000000000000000000000 P 8f2686ee72bf433493870404e6fe313d [sys.catalog]: SysCatalogTable state changed. Reason: New leader 8f2686ee72bf433493870404e6fe313d. Latest consensus state: current_term: 1 leader_uuid: "8f2686ee72bf433493870404e6fe313d" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8f2686ee72bf433493870404e6fe313d" member_type: VOTER } }
I20260812 06:18:19.489295 11475 sys_catalog.cc:458] T 00000000000000000000000000000000 P 8f2686ee72bf433493870404e6fe313d [sys.catalog]: This master's current role is: LEADER
I20260812 06:18:19.489902 11478 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:18:19.490600 11478 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:18:19.490983 11097 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:18:19.492504 11478 catalog_manager.cc:1383] Generated new cluster ID: 0edde0902ad44be8afc086046393b5d5
I20260812 06:18:19.492563 11478 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:18:19.518458 11478 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:18:19.519104 11478 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:18:19.524214 11478 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 8f2686ee72bf433493870404e6fe313d: Generated new TSK 0
I20260812 06:18:19.524438 11478 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:18:19.555542 11097 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:18:19.557775 11497 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:19.557817 11502 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:18:19.557817 11500 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:18:19.558102 11097 server_base.cc:1061] running on GCE node
I20260812 06:18:19.558277 11097 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:18:19.558353 11097 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:18:19.558386 11097 hybrid_clock.cc:648] HybridClock initialized: now 1786515499558385 us; error 0 us; skew 500 ppm
I20260812 06:18:19.559391 11097 webserver.cc:533] Webserver started at http://127.10.214.65:43127/ using document root <none> and password file <none>
I20260812 06:18:19.559577 11097 fs_manager.cc:362] Metadata directory not provided
I20260812 06:18:19.559653 11097 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:18:19.559738 11097 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:18:19.560159 11097 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515494136637-11097-0/minicluster-data/ts-0-root/instance:
uuid: "44733cf2a3144939ad58ba0c26d58782"
format_stamp: "Formatted at 2026-08-12 06:18:19 on dist-test-slave-x5fp"
I20260812 06:18:19.561816 11097 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.000s	sys 0.002s
I20260812 06:18:19.562736 11508 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:19.563001 11097 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:18:19.563093 11097 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515494136637-11097-0/minicluster-data/ts-0-root
uuid: "44733cf2a3144939ad58ba0c26d58782"
format_stamp: "Formatted at 2026-08-12 06:18:19 on dist-test-slave-x5fp"
I20260812 06:18:19.563181 11097 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515494136637-11097-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515494136637-11097-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515494136637-11097-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:18:19.593464 11097 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:18:19.593966 11097 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:18:19.594347 11097 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:18:19.594894 11097 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:18:19.594964 11097 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:19.595031 11097 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:18:19.595091 11097 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:18:19.600138 11097 rpc_server.cc:307] RPC server started. Bound to: 127.10.214.65:39225
I20260812 06:18:19.600176 11597 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.10.214.65:39225 every 8 connection(s)
I20260812 06:18:19.610153 11598 heartbeater.cc:344] Connected to a master server at 127.10.214.126:46599
I20260812 06:18:19.610312 11598 heartbeater.cc:461] Registering TS with master...
I20260812 06:18:19.610528 11598 heartbeater.cc:507] Master 127.10.214.126:46599 requested a full tablet report, sending...
I20260812 06:18:19.611285 11419 ts_manager.cc:194] Registered new tserver with Master: 44733cf2a3144939ad58ba0c26d58782 (127.10.214.65:39225)
I20260812 06:18:19.611842 11097 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.011210247s
I20260812 06:18:19.612146 11419 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:45130
I20260812 06:18:19.620164 11419 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:45136:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:18:19.629560 11551 tablet_service.cc:1511] Processing CreateTablet for tablet c820fcb7da67413fb643a69b5ffa8da8 (DEFAULT_TABLE table=heavy-update-compaction-test [id=0d1565f9f52f4416b9c37b29019fdccc]), partition=
I20260812 06:18:19.629846 11551 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet c820fcb7da67413fb643a69b5ffa8da8. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:18:19.631945 11613 tablet_bootstrap.cc:492] T c820fcb7da67413fb643a69b5ffa8da8 P 44733cf2a3144939ad58ba0c26d58782: Bootstrap starting.
I20260812 06:18:19.632831 11613 tablet_bootstrap.cc:654] T c820fcb7da67413fb643a69b5ffa8da8 P 44733cf2a3144939ad58ba0c26d58782: Neither blocks nor log segments found. Creating new log.
I20260812 06:18:19.634042 11613 tablet_bootstrap.cc:492] T c820fcb7da67413fb643a69b5ffa8da8 P 44733cf2a3144939ad58ba0c26d58782: No bootstrap required, opened a new log
I20260812 06:18:19.634178 11613 ts_tablet_manager.cc:1403] T c820fcb7da67413fb643a69b5ffa8da8 P 44733cf2a3144939ad58ba0c26d58782: Time spent bootstrapping tablet: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:18:19.634742 11613 raft_consensus.cc:359] T c820fcb7da67413fb643a69b5ffa8da8 P 44733cf2a3144939ad58ba0c26d58782 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "44733cf2a3144939ad58ba0c26d58782" member_type: VOTER last_known_addr { host: "127.10.214.65" port: 39225 } }
I20260812 06:18:19.634878 11613 raft_consensus.cc:385] T c820fcb7da67413fb643a69b5ffa8da8 P 44733cf2a3144939ad58ba0c26d58782 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:18:19.634928 11613 raft_consensus.cc:740] T c820fcb7da67413fb643a69b5ffa8da8 P 44733cf2a3144939ad58ba0c26d58782 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 44733cf2a3144939ad58ba0c26d58782, State: Initialized, Role: FOLLOWER
I20260812 06:18:19.635087 11613 consensus_queue.cc:260] T c820fcb7da67413fb643a69b5ffa8da8 P 44733cf2a3144939ad58ba0c26d58782 [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: "44733cf2a3144939ad58ba0c26d58782" member_type: VOTER last_known_addr { host: "127.10.214.65" port: 39225 } }
I20260812 06:18:19.635205 11613 raft_consensus.cc:399] T c820fcb7da67413fb643a69b5ffa8da8 P 44733cf2a3144939ad58ba0c26d58782 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:18:19.635262 11613 raft_consensus.cc:493] T c820fcb7da67413fb643a69b5ffa8da8 P 44733cf2a3144939ad58ba0c26d58782 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:18:19.635321 11613 raft_consensus.cc:3060] T c820fcb7da67413fb643a69b5ffa8da8 P 44733cf2a3144939ad58ba0c26d58782 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:18:19.636085 11613 raft_consensus.cc:515] T c820fcb7da67413fb643a69b5ffa8da8 P 44733cf2a3144939ad58ba0c26d58782 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "44733cf2a3144939ad58ba0c26d58782" member_type: VOTER last_known_addr { host: "127.10.214.65" port: 39225 } }
I20260812 06:18:19.636256 11613 leader_election.cc:304] T c820fcb7da67413fb643a69b5ffa8da8 P 44733cf2a3144939ad58ba0c26d58782 [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: 44733cf2a3144939ad58ba0c26d58782; no voters: 
I20260812 06:18:19.636497 11613 leader_election.cc:290] T c820fcb7da67413fb643a69b5ffa8da8 P 44733cf2a3144939ad58ba0c26d58782 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:18:19.636644 11616 raft_consensus.cc:2804] T c820fcb7da67413fb643a69b5ffa8da8 P 44733cf2a3144939ad58ba0c26d58782 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:18:19.636986 11598 heartbeater.cc:499] Master 127.10.214.126:46599 was elected leader, sending a full tablet report...
I20260812 06:18:19.636920 11613 ts_tablet_manager.cc:1434] T c820fcb7da67413fb643a69b5ffa8da8 P 44733cf2a3144939ad58ba0c26d58782: Time spent starting tablet: real 0.003s	user 0.000s	sys 0.003s
I20260812 06:18:19.636941 11616 raft_consensus.cc:697] T c820fcb7da67413fb643a69b5ffa8da8 P 44733cf2a3144939ad58ba0c26d58782 [term 1 LEADER]: Becoming Leader. State: Replica: 44733cf2a3144939ad58ba0c26d58782, State: Running, Role: LEADER
I20260812 06:18:19.637220 11616 consensus_queue.cc:237] T c820fcb7da67413fb643a69b5ffa8da8 P 44733cf2a3144939ad58ba0c26d58782 [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: "44733cf2a3144939ad58ba0c26d58782" member_type: VOTER last_known_addr { host: "127.10.214.65" port: 39225 } }
I20260812 06:18:19.638756 11419 catalog_manager.cc:5719] T c820fcb7da67413fb643a69b5ffa8da8 P 44733cf2a3144939ad58ba0c26d58782 reported cstate change: term changed from 0 to 1, leader changed from <none> to 44733cf2a3144939ad58ba0c26d58782 (127.10.214.65). New cstate: current_term: 1 leader_uuid: "44733cf2a3144939ad58ba0c26d58782" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "44733cf2a3144939ad58ba0c26d58782" member_type: VOTER last_known_addr { host: "127.10.214.65" port: 39225 } health_report { overall_health: HEALTHY } } }
I20260812 06:18:19.696527 11097 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.051s	user 0.014s	sys 0.008s
I20260812 06:18:19.851135 11600 maintenance_manager.cc:419] P 44733cf2a3144939ad58ba0c26d58782: Scheduling FlushMRSOp(c820fcb7da67413fb643a69b5ffa8da8): perf score=19.054940
I20260812 06:18:20.003067 11515 maintenance_manager.cc:643] P 44733cf2a3144939ad58ba0c26d58782: FlushMRSOp(c820fcb7da67413fb643a69b5ffa8da8) complete. Timing: real 0.152s	user 0.099s	sys 0.047s Metrics: {"bytes_written":11897249,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":141,"dirs.run_cpu_time_us":159,"dirs.run_wall_time_us":742,"drs_written":1,"lbm_read_time_us":60,"lbm_reads_lt_1ms":4,"lbm_write_time_us":40354,"lbm_writes_lt_1ms":757,"peak_mem_usage":0,"reinsert_count":0,"rows_written":105,"update_count":1450}
I20260812 06:18:20.003661 11600 maintenance_manager.cc:419] P 44733cf2a3144939ad58ba0c26d58782: Scheduling LogGCOp(c820fcb7da67413fb643a69b5ffa8da8): free 20743880 bytes of WAL
I20260812 06:18:20.003897 11515 log_reader.cc:385] T c820fcb7da67413fb643a69b5ffa8da8: removed 2 log segments from log reader
I20260812 06:18:20.003947 11515 log.cc:1079] T c820fcb7da67413fb643a69b5ffa8da8 P 44733cf2a3144939ad58ba0c26d58782: Deleting log segment in path: /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515494136637-11097-0/minicluster-data/ts-0-root/wals/c820fcb7da67413fb643a69b5ffa8da8/wal-000000001 (ops 1-6)
I20260812 06:18:20.003996 11515 log.cc:1079] T c820fcb7da67413fb643a69b5ffa8da8 P 44733cf2a3144939ad58ba0c26d58782: Deleting log segment in path: /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515494136637-11097-0/minicluster-data/ts-0-root/wals/c820fcb7da67413fb643a69b5ffa8da8/wal-000000002 (ops 7-11)
I20260812 06:18:20.008244 11515 maintenance_manager.cc:643] P 44733cf2a3144939ad58ba0c26d58782: LogGCOp(c820fcb7da67413fb643a69b5ffa8da8) complete. Timing: real 0.004s	user 0.000s	sys 0.001s Metrics: {}
I20260812 06:18:20.008591 11600 maintenance_manager.cc:419] P 44733cf2a3144939ad58ba0c26d58782: Scheduling FlushDeltaMemStoresOp(c820fcb7da67413fb643a69b5ffa8da8): perf score=2.188937
I20260812 06:18:20.026700 11515 maintenance_manager.cc:643] P 44733cf2a3144939ad58ba0c26d58782: FlushDeltaMemStoresOp(c820fcb7da67413fb643a69b5ffa8da8) complete. Timing: real 0.018s	user 0.013s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5838,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:20.027266 11600 maintenance_manager.cc:419] P 44733cf2a3144939ad58ba0c26d58782: Scheduling UndoDeltaBlockGCOp(c820fcb7da67413fb643a69b5ffa8da8): 16821648 bytes on disk
I20260812 06:18:20.027657 11515 maintenance_manager.cc:643] P 44733cf2a3144939ad58ba0c26d58782: UndoDeltaBlockGCOp(c820fcb7da67413fb643a69b5ffa8da8) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":64,"lbm_reads_lt_1ms":4}
I20260812 06:18:20.028115 11600 maintenance_manager.cc:419] P 44733cf2a3144939ad58ba0c26d58782: Scheduling MajorDeltaCompactionOp(c820fcb7da67413fb643a69b5ffa8da8): perf score=1.000000
I20260812 06:18:20.169281 11515 maintenance_manager.cc:643] P 44733cf2a3144939ad58ba0c26d58782: MajorDeltaCompactionOp(c820fcb7da67413fb643a69b5ffa8da8) complete. Timing: real 0.141s	user 0.113s	sys 0.020s Metrics: {"cfile_cache_miss":422,"cfile_cache_miss_bytes":20303031,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":594,"lbm_read_time_us":9621,"lbm_reads_lt_1ms":450,"lbm_write_time_us":23846,"lbm_writes_lt_1ms":433,"mutex_wait_us":37,"peak_mem_usage":49238594,"reinsert_count":0,"thread_start_us":418,"threads_started":5,"update_count":1950}
I20260812 06:18:20.169838 11600 maintenance_manager.cc:419] P 44733cf2a3144939ad58ba0c26d58782: Scheduling FlushDeltaMemStoresOp(c820fcb7da67413fb643a69b5ffa8da8): perf score=14.095187
I20260812 06:18:20.218355 11515 maintenance_manager.cc:643] P 44733cf2a3144939ad58ba0c26d58782: FlushDeltaMemStoresOp(c820fcb7da67413fb643a69b5ffa8da8) complete. Timing: real 0.048s	user 0.027s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18205,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:20.218784 11600 maintenance_manager.cc:419] P 44733cf2a3144939ad58ba0c26d58782: Scheduling FlushDeltaMemStoresOp(c820fcb7da67413fb643a69b5ffa8da8): perf score=2.188937
I20260812 06:18:20.230238 11515 maintenance_manager.cc:643] P 44733cf2a3144939ad58ba0c26d58782: FlushDeltaMemStoresOp(c820fcb7da67413fb643a69b5ffa8da8) complete. Timing: real 0.011s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3921,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:20.230703 11600 maintenance_manager.cc:419] P 44733cf2a3144939ad58ba0c26d58782: Scheduling MajorDeltaCompactionOp(c820fcb7da67413fb643a69b5ffa8da8): perf score=1.000000
I20260812 06:18:20.386868 11515 maintenance_manager.cc:643] P 44733cf2a3144939ad58ba0c26d58782: MajorDeltaCompactionOp(c820fcb7da67413fb643a69b5ffa8da8) complete. Timing: real 0.156s	user 0.116s	sys 0.037s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":858,"lbm_read_time_us":11973,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29057,"lbm_writes_lt_1ms":543,"mutex_wait_us":343,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11648,"update_count":2500}
I20260812 06:18:20.387588 11600 maintenance_manager.cc:419] P 44733cf2a3144939ad58ba0c26d58782: Scheduling FlushDeltaMemStoresOp(c820fcb7da67413fb643a69b5ffa8da8): perf score=12.110812
I20260812 06:18:20.429821 11515 maintenance_manager.cc:643] P 44733cf2a3144939ad58ba0c26d58782: FlushDeltaMemStoresOp(c820fcb7da67413fb643a69b5ffa8da8) complete. Timing: real 0.042s	user 0.018s	sys 0.020s Metrics: {"bytes_written":13497195,"delete_count":0,"lbm_write_time_us":17180,"lbm_writes_lt_1ms":332,"reinsert_count":0,"update_count":1645}
I20260812 06:18:20.430384 11600 maintenance_manager.cc:419] P 44733cf2a3144939ad58ba0c26d58782: Scheduling FlushDeltaMemStoresOp(c820fcb7da67413fb643a69b5ffa8da8): perf score=2.188937
I20260812 06:18:20.450546 11515 maintenance_manager.cc:643] P 44733cf2a3144939ad58ba0c26d58782: FlushDeltaMemStoresOp(c820fcb7da67413fb643a69b5ffa8da8) complete. Timing: real 0.020s	user 0.005s	sys 0.005s Metrics: {"bytes_written":3323184,"delete_count":0,"lbm_write_time_us":4227,"lbm_writes_lt_1ms":84,"reinsert_count":0,"update_count":405}
I20260812 06:18:20.450987 11600 maintenance_manager.cc:419] P 44733cf2a3144939ad58ba0c26d58782: Scheduling FlushDeltaMemStoresOp(c820fcb7da67413fb643a69b5ffa8da8): perf score=2.188937
I20260812 06:18:20.460481 11515 maintenance_manager.cc:643] P 44733cf2a3144939ad58ba0c26d58782: FlushDeltaMemStoresOp(c820fcb7da67413fb643a69b5ffa8da8) complete. Timing: real 0.009s	user 0.003s	sys 0.005s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3550,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:20.460918 11600 maintenance_manager.cc:419] P 44733cf2a3144939ad58ba0c26d58782: Scheduling MajorDeltaCompactionOp(c820fcb7da67413fb643a69b5ffa8da8): perf score=1.000000
I20260812 06:18:20.645881 11515 maintenance_manager.cc:643] P 44733cf2a3144939ad58ba0c26d58782: MajorDeltaCompactionOp(c820fcb7da67413fb643a69b5ffa8da8) complete. Timing: real 0.185s	user 0.143s	sys 0.036s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24815779,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":845,"lbm_read_time_us":12564,"lbm_reads_lt_1ms":573,"lbm_write_time_us":29579,"lbm_writes_lt_1ms":543,"mutex_wait_us":296,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2432,"update_count":2500}
I20260812 06:18:20.646343 11600 maintenance_manager.cc:419] P 44733cf2a3144939ad58ba0c26d58782: Scheduling FlushDeltaMemStoresOp(c820fcb7da67413fb643a69b5ffa8da8): perf score=14.095187
I20260812 06:18:20.706168 11515 maintenance_manager.cc:643] P 44733cf2a3144939ad58ba0c26d58782: FlushDeltaMemStoresOp(c820fcb7da67413fb643a69b5ffa8da8) complete. Timing: real 0.060s	user 0.024s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22510,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:20.706620 11600 maintenance_manager.cc:419] P 44733cf2a3144939ad58ba0c26d58782: Scheduling FlushDeltaMemStoresOp(c820fcb7da67413fb643a69b5ffa8da8): perf score=2.188937
I20260812 06:18:20.717209 11515 maintenance_manager.cc:643] P 44733cf2a3144939ad58ba0c26d58782: FlushDeltaMemStoresOp(c820fcb7da67413fb643a69b5ffa8da8) complete. Timing: real 0.010s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4109,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:20.717643 11600 maintenance_manager.cc:419] P 44733cf2a3144939ad58ba0c26d58782: Scheduling MajorDeltaCompactionOp(c820fcb7da67413fb643a69b5ffa8da8): perf score=1.000000
I20260812 06:18:20.888062 11515 maintenance_manager.cc:643] P 44733cf2a3144939ad58ba0c26d58782: MajorDeltaCompactionOp(c820fcb7da67413fb643a69b5ffa8da8) complete. Timing: real 0.170s	user 0.144s	sys 0.023s 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":185,"lbm_read_time_us":14153,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28184,"lbm_writes_lt_1ms":543,"mutex_wait_us":2,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":6528,"update_count":2500}
I20260812 06:18:20.888593 11600 maintenance_manager.cc:419] P 44733cf2a3144939ad58ba0c26d58782: Scheduling FlushDeltaMemStoresOp(c820fcb7da67413fb643a69b5ffa8da8): perf score=14.095187
I20260812 06:18:20.950014 11515 maintenance_manager.cc:643] P 44733cf2a3144939ad58ba0c26d58782: FlushDeltaMemStoresOp(c820fcb7da67413fb643a69b5ffa8da8) complete. Timing: real 0.061s	user 0.032s	sys 0.028s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":24113,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:18:20.950652 11600 maintenance_manager.cc:419] P 44733cf2a3144939ad58ba0c26d58782: Scheduling FlushDeltaMemStoresOp(c820fcb7da67413fb643a69b5ffa8da8): perf score=2.188937
I20260812 06:18:20.963181 11515 maintenance_manager.cc:643] P 44733cf2a3144939ad58ba0c26d58782: FlushDeltaMemStoresOp(c820fcb7da67413fb643a69b5ffa8da8) complete. Timing: real 0.012s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4462,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:20.963869 11600 maintenance_manager.cc:419] P 44733cf2a3144939ad58ba0c26d58782: Scheduling MajorDeltaCompactionOp(c820fcb7da67413fb643a69b5ffa8da8): perf score=1.000000
I20260812 06:18:21.154978 11515 maintenance_manager.cc:643] P 44733cf2a3144939ad58ba0c26d58782: MajorDeltaCompactionOp(c820fcb7da67413fb643a69b5ffa8da8) complete. Timing: real 0.191s	user 0.118s	sys 0.071s 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":1350,"lbm_read_time_us":14572,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31305,"lbm_writes_lt_1ms":543,"mutex_wait_us":573,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2048,"update_count":2500}
I20260812 06:18:21.155472 11600 maintenance_manager.cc:419] P 44733cf2a3144939ad58ba0c26d58782: Scheduling FlushDeltaMemStoresOp(c820fcb7da67413fb643a69b5ffa8da8): perf score=14.095187
I20260812 06:18:21.220139 11515 maintenance_manager.cc:643] P 44733cf2a3144939ad58ba0c26d58782: FlushDeltaMemStoresOp(c820fcb7da67413fb643a69b5ffa8da8) complete. Timing: real 0.064s	user 0.024s	sys 0.031s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22585,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:21.220618 11600 maintenance_manager.cc:419] P 44733cf2a3144939ad58ba0c26d58782: Scheduling FlushDeltaMemStoresOp(c820fcb7da67413fb643a69b5ffa8da8): perf score=2.188937
I20260812 06:18:21.231244 11515 maintenance_manager.cc:643] P 44733cf2a3144939ad58ba0c26d58782: FlushDeltaMemStoresOp(c820fcb7da67413fb643a69b5ffa8da8) complete. Timing: real 0.010s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4162,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:21.231719 11600 maintenance_manager.cc:419] P 44733cf2a3144939ad58ba0c26d58782: Scheduling FlushMRSOp(c820fcb7da67413fb643a69b5ffa8da8): perf score=1.000000
I20260812 06:18:21.270725 11515 maintenance_manager.cc:643] P 44733cf2a3144939ad58ba0c26d58782: FlushMRSOp(c820fcb7da67413fb643a69b5ffa8da8) complete. Timing: real 0.039s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1152508,"cfile_init":1,"dirs.queue_time_us":70,"dirs.run_cpu_time_us":196,"dirs.run_wall_time_us":1462,"drs_written":1,"lbm_read_time_us":43,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1320,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:21.271381 11600 maintenance_manager.cc:419] P 44733cf2a3144939ad58ba0c26d58782: Scheduling LogGCOp(c820fcb7da67413fb643a69b5ffa8da8): free 115943184 bytes of WAL
I20260812 06:18:21.271639 11515 log_reader.cc:385] T c820fcb7da67413fb643a69b5ffa8da8: removed 11 log segments from log reader
I20260812 06:18:21.271744 11515 log.cc:1079] T c820fcb7da67413fb643a69b5ffa8da8 P 44733cf2a3144939ad58ba0c26d58782: Deleting log segment in path: /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515494136637-11097-0/minicluster-data/ts-0-root/wals/c820fcb7da67413fb643a69b5ffa8da8/wal-000000003 (ops 12-16)
I20260812 06:18:21.271802 11515 log.cc:1079] T c820fcb7da67413fb643a69b5ffa8da8 P 44733cf2a3144939ad58ba0c26d58782: Deleting log segment in path: /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515494136637-11097-0/minicluster-data/ts-0-root/wals/c820fcb7da67413fb643a69b5ffa8da8/wal-000000004 (ops 17-21)
I20260812 06:18:21.271860 11515 log.cc:1079] T c820fcb7da67413fb643a69b5ffa8da8 P 44733cf2a3144939ad58ba0c26d58782: Deleting log segment in path: /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515494136637-11097-0/minicluster-data/ts-0-root/wals/c820fcb7da67413fb643a69b5ffa8da8/wal-000000005 (ops 22-26)
I20260812 06:18:21.271905 11515 log.cc:1079] T c820fcb7da67413fb643a69b5ffa8da8 P 44733cf2a3144939ad58ba0c26d58782: Deleting log segment in path: /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515494136637-11097-0/minicluster-data/ts-0-root/wals/c820fcb7da67413fb643a69b5ffa8da8/wal-000000006 (ops 27-31)
I20260812 06:18:21.271946 11515 log.cc:1079] T c820fcb7da67413fb643a69b5ffa8da8 P 44733cf2a3144939ad58ba0c26d58782: Deleting log segment in path: /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515494136637-11097-0/minicluster-data/ts-0-root/wals/c820fcb7da67413fb643a69b5ffa8da8/wal-000000007 (ops 32-36)
I20260812 06:18:21.271986 11515 log.cc:1079] T c820fcb7da67413fb643a69b5ffa8da8 P 44733cf2a3144939ad58ba0c26d58782: Deleting log segment in path: /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515494136637-11097-0/minicluster-data/ts-0-root/wals/c820fcb7da67413fb643a69b5ffa8da8/wal-000000008 (ops 37-41)
I20260812 06:18:21.272024 11515 log.cc:1079] T c820fcb7da67413fb643a69b5ffa8da8 P 44733cf2a3144939ad58ba0c26d58782: Deleting log segment in path: /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515494136637-11097-0/minicluster-data/ts-0-root/wals/c820fcb7da67413fb643a69b5ffa8da8/wal-000000009 (ops 42-46)
I20260812 06:18:21.272064 11515 log.cc:1079] T c820fcb7da67413fb643a69b5ffa8da8 P 44733cf2a3144939ad58ba0c26d58782: Deleting log segment in path: /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515494136637-11097-0/minicluster-data/ts-0-root/wals/c820fcb7da67413fb643a69b5ffa8da8/wal-000000010 (ops 47-51)
I20260812 06:18:21.272104 11515 log.cc:1079] T c820fcb7da67413fb643a69b5ffa8da8 P 44733cf2a3144939ad58ba0c26d58782: Deleting log segment in path: /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515494136637-11097-0/minicluster-data/ts-0-root/wals/c820fcb7da67413fb643a69b5ffa8da8/wal-000000011 (ops 52-56)
I20260812 06:18:21.272142 11515 log.cc:1079] T c820fcb7da67413fb643a69b5ffa8da8 P 44733cf2a3144939ad58ba0c26d58782: Deleting log segment in path: /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515494136637-11097-0/minicluster-data/ts-0-root/wals/c820fcb7da67413fb643a69b5ffa8da8/wal-000000012 (ops 57-61)
I20260812 06:18:21.272181 11515 log.cc:1079] T c820fcb7da67413fb643a69b5ffa8da8 P 44733cf2a3144939ad58ba0c26d58782: Deleting log segment in path: /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515494136637-11097-0/minicluster-data/ts-0-root/wals/c820fcb7da67413fb643a69b5ffa8da8/wal-000000013 (ops 62-66)
I20260812 06:18:21.298311 11515 maintenance_manager.cc:643] P 44733cf2a3144939ad58ba0c26d58782: LogGCOp(c820fcb7da67413fb643a69b5ffa8da8) complete. Timing: real 0.027s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:18:21.298715 11600 maintenance_manager.cc:419] P 44733cf2a3144939ad58ba0c26d58782: Scheduling FlushDeltaMemStoresOp(c820fcb7da67413fb643a69b5ffa8da8): perf score=3.181125
I20260812 06:18:21.321679 11515 maintenance_manager.cc:643] P 44733cf2a3144939ad58ba0c26d58782: FlushDeltaMemStoresOp(c820fcb7da67413fb643a69b5ffa8da8) complete. Timing: real 0.023s	user 0.011s	sys 0.006s Metrics: {"bytes_written":4512903,"delete_count":0,"lbm_write_time_us":7026,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:21.322131 11600 maintenance_manager.cc:419] P 44733cf2a3144939ad58ba0c26d58782: Scheduling FlushDeltaMemStoresOp(c820fcb7da67413fb643a69b5ffa8da8): perf score=2.188937
I20260812 06:18:21.331864 11515 maintenance_manager.cc:643] P 44733cf2a3144939ad58ba0c26d58782: FlushDeltaMemStoresOp(c820fcb7da67413fb643a69b5ffa8da8) complete. Timing: real 0.010s	user 0.000s	sys 0.008s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3662,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:21.332332 11600 maintenance_manager.cc:419] P 44733cf2a3144939ad58ba0c26d58782: Scheduling UndoDeltaBlockGCOp(c820fcb7da67413fb643a69b5ffa8da8): 447 bytes on disk
I20260812 06:18:21.332839 11515 maintenance_manager.cc:643] P 44733cf2a3144939ad58ba0c26d58782: UndoDeltaBlockGCOp(c820fcb7da67413fb643a69b5ffa8da8) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":65,"lbm_reads_lt_1ms":4}
I20260812 06:18:21.333267 11600 maintenance_manager.cc:419] P 44733cf2a3144939ad58ba0c26d58782: Scheduling MajorDeltaCompactionOp(c820fcb7da67413fb643a69b5ffa8da8): perf score=1.000000
I20260812 06:18:21.568511 11515 maintenance_manager.cc:643] P 44733cf2a3144939ad58ba0c26d58782: MajorDeltaCompactionOp(c820fcb7da67413fb643a69b5ffa8da8) complete. Timing: real 0.235s	user 0.159s	sys 0.067s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020736,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":215,"lbm_read_time_us":16378,"lbm_reads_lt_1ms":774,"lbm_write_time_us":38666,"lbm_writes_lt_1ms":743,"mutex_wait_us":632,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":14720,"thread_start_us":77,"threads_started":1,"update_count":3500}
I20260812 06:18:21.569039 11600 maintenance_manager.cc:419] P 44733cf2a3144939ad58ba0c26d58782: Scheduling FlushDeltaMemStoresOp(c820fcb7da67413fb643a69b5ffa8da8): perf score=18.063937
I20260812 06:18:21.642556 11515 maintenance_manager.cc:643] P 44733cf2a3144939ad58ba0c26d58782: FlushDeltaMemStoresOp(c820fcb7da67413fb643a69b5ffa8da8) complete. Timing: real 0.073s	user 0.044s	sys 0.018s Metrics: {"bytes_written":20512317,"delete_count":0,"lbm_write_time_us":28991,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:21.643095 11600 maintenance_manager.cc:419] P 44733cf2a3144939ad58ba0c26d58782: Scheduling FlushDeltaMemStoresOp(c820fcb7da67413fb643a69b5ffa8da8): perf score=2.188937
I20260812 06:18:21.655745 11515 maintenance_manager.cc:643] P 44733cf2a3144939ad58ba0c26d58782: FlushDeltaMemStoresOp(c820fcb7da67413fb643a69b5ffa8da8) complete. Timing: real 0.012s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4267,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:21.656355 11600 maintenance_manager.cc:419] P 44733cf2a3144939ad58ba0c26d58782: Scheduling MajorDeltaCompactionOp(c820fcb7da67413fb643a69b5ffa8da8): perf score=1.000000
I20260812 06:18:21.846397 11515 maintenance_manager.cc:643] P 44733cf2a3144939ad58ba0c26d58782: MajorDeltaCompactionOp(c820fcb7da67413fb643a69b5ffa8da8) complete. Timing: real 0.190s	user 0.137s	sys 0.051s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918099,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":219,"lbm_read_time_us":13523,"lbm_reads_lt_1ms":668,"lbm_write_time_us":31550,"lbm_writes_lt_1ms":643,"mutex_wait_us":47,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":3000}
I20260812 06:18:21.847118 11600 maintenance_manager.cc:419] P 44733cf2a3144939ad58ba0c26d58782: Scheduling FlushDeltaMemStoresOp(c820fcb7da67413fb643a69b5ffa8da8): perf score=15.087375
I20260812 06:18:21.915745 11515 maintenance_manager.cc:643] P 44733cf2a3144939ad58ba0c26d58782: FlushDeltaMemStoresOp(c820fcb7da67413fb643a69b5ffa8da8) complete. Timing: real 0.068s	user 0.029s	sys 0.027s Metrics: {"bytes_written":16820146,"delete_count":0,"lbm_write_time_us":26763,"lbm_writes_lt_1ms":413,"reinsert_count":0,"update_count":2050}
I20260812 06:18:21.916210 11600 maintenance_manager.cc:419] P 44733cf2a3144939ad58ba0c26d58782: Scheduling FlushDeltaMemStoresOp(c820fcb7da67413fb643a69b5ffa8da8): perf score=6.157687
I20260812 06:18:21.940512 11515 maintenance_manager.cc:643] P 44733cf2a3144939ad58ba0c26d58782: FlushDeltaMemStoresOp(c820fcb7da67413fb643a69b5ffa8da8) complete. Timing: real 0.024s	user 0.010s	sys 0.011s Metrics: {"bytes_written":7794838,"delete_count":0,"lbm_write_time_us":9973,"lbm_writes_lt_1ms":193,"reinsert_count":0,"update_count":950}
I20260812 06:18:21.941067 11600 maintenance_manager.cc:419] P 44733cf2a3144939ad58ba0c26d58782: Scheduling MajorDeltaCompactionOp(c820fcb7da67413fb643a69b5ffa8da8): perf score=1.000000
I20260812 06:18:22.113252 11515 maintenance_manager.cc:643] P 44733cf2a3144939ad58ba0c26d58782: MajorDeltaCompactionOp(c820fcb7da67413fb643a69b5ffa8da8) complete. Timing: real 0.172s	user 0.146s	sys 0.024s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918101,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":260,"lbm_read_time_us":13634,"lbm_reads_lt_1ms":664,"lbm_write_time_us":34376,"lbm_writes_lt_1ms":643,"mutex_wait_us":23,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":13952,"update_count":3000}
I20260812 06:18:22.113988 11600 maintenance_manager.cc:419] P 44733cf2a3144939ad58ba0c26d58782: Scheduling FlushDeltaMemStoresOp(c820fcb7da67413fb643a69b5ffa8da8): perf score=14.095187
I20260812 06:18:22.173724 11515 maintenance_manager.cc:643] P 44733cf2a3144939ad58ba0c26d58782: FlushDeltaMemStoresOp(c820fcb7da67413fb643a69b5ffa8da8) complete. Timing: real 0.059s	user 0.038s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":25514,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:22.174361 11600 maintenance_manager.cc:419] P 44733cf2a3144939ad58ba0c26d58782: Scheduling FlushDeltaMemStoresOp(c820fcb7da67413fb643a69b5ffa8da8): perf score=2.188937
I20260812 06:18:22.190464 11515 maintenance_manager.cc:643] P 44733cf2a3144939ad58ba0c26d58782: FlushDeltaMemStoresOp(c820fcb7da67413fb643a69b5ffa8da8) complete. Timing: real 0.016s	user 0.005s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5342,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:22.191008 11600 maintenance_manager.cc:419] P 44733cf2a3144939ad58ba0c26d58782: Scheduling FlushDeltaMemStoresOp(c820fcb7da67413fb643a69b5ffa8da8): perf score=2.188937
I20260812 06:18:22.201467 11515 maintenance_manager.cc:643] P 44733cf2a3144939ad58ba0c26d58782: FlushDeltaMemStoresOp(c820fcb7da67413fb643a69b5ffa8da8) complete. Timing: real 0.010s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3959,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:22.202028 11600 maintenance_manager.cc:419] P 44733cf2a3144939ad58ba0c26d58782: Scheduling MajorDeltaCompactionOp(c820fcb7da67413fb643a69b5ffa8da8): perf score=1.000000
I20260812 06:18:22.372223 11515 maintenance_manager.cc:643] P 44733cf2a3144939ad58ba0c26d58782: MajorDeltaCompactionOp(c820fcb7da67413fb643a69b5ffa8da8) complete. Timing: real 0.170s	user 0.114s	sys 0.056s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918213,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":393,"lbm_read_time_us":13872,"lbm_reads_lt_1ms":673,"lbm_write_time_us":33576,"lbm_writes_lt_1ms":643,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":7424,"update_count":3000}
I20260812 06:18:22.373052 11600 maintenance_manager.cc:419] P 44733cf2a3144939ad58ba0c26d58782: Scheduling FlushDeltaMemStoresOp(c820fcb7da67413fb643a69b5ffa8da8): perf score=14.095187
I20260812 06:18:22.419628 11515 maintenance_manager.cc:643] P 44733cf2a3144939ad58ba0c26d58782: FlushDeltaMemStoresOp(c820fcb7da67413fb643a69b5ffa8da8) complete. Timing: real 0.046s	user 0.015s	sys 0.025s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19172,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:22.420145 11600 maintenance_manager.cc:419] P 44733cf2a3144939ad58ba0c26d58782: Scheduling FlushDeltaMemStoresOp(c820fcb7da67413fb643a69b5ffa8da8): perf score=2.188937
I20260812 06:18:22.430619 11515 maintenance_manager.cc:643] P 44733cf2a3144939ad58ba0c26d58782: FlushDeltaMemStoresOp(c820fcb7da67413fb643a69b5ffa8da8) complete. Timing: real 0.010s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":3998,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:22.431087 11600 maintenance_manager.cc:419] P 44733cf2a3144939ad58ba0c26d58782: Scheduling MajorDeltaCompactionOp(c820fcb7da67413fb643a69b5ffa8da8): perf score=1.000000
I20260812 06:18:22.601011 11515 maintenance_manager.cc:643] P 44733cf2a3144939ad58ba0c26d58782: MajorDeltaCompactionOp(c820fcb7da67413fb643a69b5ffa8da8) complete. Timing: real 0.170s	user 0.138s	sys 0.023s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815682,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":3526,"lbm_read_time_us":12324,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29639,"lbm_writes_lt_1ms":543,"mutex_wait_us":3098,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":7296,"update_count":2500}
I20260812 06:18:22.601933 11600 maintenance_manager.cc:419] P 44733cf2a3144939ad58ba0c26d58782: Scheduling FlushDeltaMemStoresOp(c820fcb7da67413fb643a69b5ffa8da8): perf score=12.110812
I20260812 06:18:22.643324 11515 maintenance_manager.cc:643] P 44733cf2a3144939ad58ba0c26d58782: FlushDeltaMemStoresOp(c820fcb7da67413fb643a69b5ffa8da8) complete. Timing: real 0.039s	user 0.024s	sys 0.012s Metrics: {"bytes_written":14768932,"delete_count":0,"lbm_write_time_us":17247,"lbm_writes_lt_1ms":363,"reinsert_count":0,"update_count":1800}
I20260812 06:18:22.643822 11600 maintenance_manager.cc:419] P 44733cf2a3144939ad58ba0c26d58782: Scheduling FlushDeltaMemStoresOp(c820fcb7da67413fb643a69b5ffa8da8): perf score=1.000000
I20260812 06:18:22.656582 11515 maintenance_manager.cc:643] P 44733cf2a3144939ad58ba0c26d58782: FlushDeltaMemStoresOp(c820fcb7da67413fb643a69b5ffa8da8) complete. Timing: real 0.013s	user 0.005s	sys 0.000s Metrics: {"bytes_written":1641152,"delete_count":0,"lbm_write_time_us":2026,"lbm_writes_lt_1ms":43,"reinsert_count":0,"update_count":200}
I20260812 06:18:22.657294 11600 maintenance_manager.cc:419] P 44733cf2a3144939ad58ba0c26d58782: Scheduling FlushMRSOp(c820fcb7da67413fb643a69b5ffa8da8): perf score=1.000000
I20260812 06:18:22.697883 11515 maintenance_manager.cc:643] P 44733cf2a3144939ad58ba0c26d58782: FlushMRSOp(c820fcb7da67413fb643a69b5ffa8da8) complete. Timing: real 0.040s	user 0.027s	sys 0.001s Metrics: {"bytes_written":1234479,"cfile_init":1,"dirs.queue_time_us":56,"dirs.run_cpu_time_us":217,"dirs.run_wall_time_us":1463,"drs_written":1,"lbm_read_time_us":53,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1903,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:18:22.698727 11600 maintenance_manager.cc:419] P 44733cf2a3144939ad58ba0c26d58782: Scheduling LogGCOp(c820fcb7da67413fb643a69b5ffa8da8): free 124710298 bytes of WAL
I20260812 06:18:22.699018 11515 log_reader.cc:385] T c820fcb7da67413fb643a69b5ffa8da8: removed 12 log segments from log reader
I20260812 06:18:22.699100 11515 log.cc:1079] T c820fcb7da67413fb643a69b5ffa8da8 P 44733cf2a3144939ad58ba0c26d58782: Deleting log segment in path: /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515494136637-11097-0/minicluster-data/ts-0-root/wals/c820fcb7da67413fb643a69b5ffa8da8/wal-000000014 (ops 67-71)
I20260812 06:18:22.699158 11515 log.cc:1079] T c820fcb7da67413fb643a69b5ffa8da8 P 44733cf2a3144939ad58ba0c26d58782: Deleting log segment in path: /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515494136637-11097-0/minicluster-data/ts-0-root/wals/c820fcb7da67413fb643a69b5ffa8da8/wal-000000015 (ops 72-76)
I20260812 06:18:22.699205 11515 log.cc:1079] T c820fcb7da67413fb643a69b5ffa8da8 P 44733cf2a3144939ad58ba0c26d58782: Deleting log segment in path: /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515494136637-11097-0/minicluster-data/ts-0-root/wals/c820fcb7da67413fb643a69b5ffa8da8/wal-000000016 (ops 77-81)
I20260812 06:18:22.699251 11515 log.cc:1079] T c820fcb7da67413fb643a69b5ffa8da8 P 44733cf2a3144939ad58ba0c26d58782: Deleting log segment in path: /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515494136637-11097-0/minicluster-data/ts-0-root/wals/c820fcb7da67413fb643a69b5ffa8da8/wal-000000017 (ops 82-86)
I20260812 06:18:22.699295 11515 log.cc:1079] T c820fcb7da67413fb643a69b5ffa8da8 P 44733cf2a3144939ad58ba0c26d58782: Deleting log segment in path: /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515494136637-11097-0/minicluster-data/ts-0-root/wals/c820fcb7da67413fb643a69b5ffa8da8/wal-000000018 (ops 87-91)
I20260812 06:18:22.699340 11515 log.cc:1079] T c820fcb7da67413fb643a69b5ffa8da8 P 44733cf2a3144939ad58ba0c26d58782: Deleting log segment in path: /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515494136637-11097-0/minicluster-data/ts-0-root/wals/c820fcb7da67413fb643a69b5ffa8da8/wal-000000019 (ops 92-96)
I20260812 06:18:22.699385 11515 log.cc:1079] T c820fcb7da67413fb643a69b5ffa8da8 P 44733cf2a3144939ad58ba0c26d58782: Deleting log segment in path: /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515494136637-11097-0/minicluster-data/ts-0-root/wals/c820fcb7da67413fb643a69b5ffa8da8/wal-000000020 (ops 97-101)
I20260812 06:18:22.699429 11515 log.cc:1079] T c820fcb7da67413fb643a69b5ffa8da8 P 44733cf2a3144939ad58ba0c26d58782: Deleting log segment in path: /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515494136637-11097-0/minicluster-data/ts-0-root/wals/c820fcb7da67413fb643a69b5ffa8da8/wal-000000021 (ops 102-106)
I20260812 06:18:22.699472 11515 log.cc:1079] T c820fcb7da67413fb643a69b5ffa8da8 P 44733cf2a3144939ad58ba0c26d58782: Deleting log segment in path: /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515494136637-11097-0/minicluster-data/ts-0-root/wals/c820fcb7da67413fb643a69b5ffa8da8/wal-000000022 (ops 107-111)
I20260812 06:18:22.699517 11515 log.cc:1079] T c820fcb7da67413fb643a69b5ffa8da8 P 44733cf2a3144939ad58ba0c26d58782: Deleting log segment in path: /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515494136637-11097-0/minicluster-data/ts-0-root/wals/c820fcb7da67413fb643a69b5ffa8da8/wal-000000023 (ops 112-116)
I20260812 06:18:22.699561 11515 log.cc:1079] T c820fcb7da67413fb643a69b5ffa8da8 P 44733cf2a3144939ad58ba0c26d58782: Deleting log segment in path: /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515494136637-11097-0/minicluster-data/ts-0-root/wals/c820fcb7da67413fb643a69b5ffa8da8/wal-000000024 (ops 117-121)
I20260812 06:18:22.699605 11515 log.cc:1079] T c820fcb7da67413fb643a69b5ffa8da8 P 44733cf2a3144939ad58ba0c26d58782: Deleting log segment in path: /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515494136637-11097-0/minicluster-data/ts-0-root/wals/c820fcb7da67413fb643a69b5ffa8da8/wal-000000025 (ops 122-126)
I20260812 06:18:22.727944 11515 maintenance_manager.cc:643] P 44733cf2a3144939ad58ba0c26d58782: LogGCOp(c820fcb7da67413fb643a69b5ffa8da8) complete. Timing: real 0.029s	user 0.000s	sys 0.026s Metrics: {}
I20260812 06:18:22.728436 11600 maintenance_manager.cc:419] P 44733cf2a3144939ad58ba0c26d58782: Scheduling UndoDeltaBlockGCOp(c820fcb7da67413fb643a69b5ffa8da8): 472 bytes on disk
I20260812 06:18:22.729092 11515 maintenance_manager.cc:643] P 44733cf2a3144939ad58ba0c26d58782: UndoDeltaBlockGCOp(c820fcb7da67413fb643a69b5ffa8da8) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":89,"lbm_reads_lt_1ms":4}
I20260812 06:18:22.729652 11600 maintenance_manager.cc:419] P 44733cf2a3144939ad58ba0c26d58782: Scheduling FlushDeltaMemStoresOp(c820fcb7da67413fb643a69b5ffa8da8): perf score=6.157687
I20260812 06:18:22.757161 11515 maintenance_manager.cc:643] P 44733cf2a3144939ad58ba0c26d58782: FlushDeltaMemStoresOp(c820fcb7da67413fb643a69b5ffa8da8) complete. Timing: real 0.027s	user 0.016s	sys 0.008s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":10968,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:18:22.757647 11600 maintenance_manager.cc:419] P 44733cf2a3144939ad58ba0c26d58782: Scheduling MajorDeltaCompactionOp(c820fcb7da67413fb643a69b5ffa8da8): perf score=1.000000
I20260812 06:18:22.952838 11515 maintenance_manager.cc:643] P 44733cf2a3144939ad58ba0c26d58782: MajorDeltaCompactionOp(c820fcb7da67413fb643a69b5ffa8da8) complete. Timing: real 0.195s	user 0.134s	sys 0.060s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918152,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":1345,"lbm_read_time_us":13983,"lbm_reads_lt_1ms":665,"lbm_write_time_us":32569,"lbm_writes_lt_1ms":643,"mutex_wait_us":302,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":22272,"thread_start_us":98,"threads_started":1,"update_count":3000}
I20260812 06:18:22.953469 11600 maintenance_manager.cc:419] P 44733cf2a3144939ad58ba0c26d58782: Scheduling FlushDeltaMemStoresOp(c820fcb7da67413fb643a69b5ffa8da8): perf score=18.063937
I20260812 06:18:23.027737 11515 maintenance_manager.cc:643] P 44733cf2a3144939ad58ba0c26d58782: FlushDeltaMemStoresOp(c820fcb7da67413fb643a69b5ffa8da8) complete. Timing: real 0.074s	user 0.028s	sys 0.039s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":31411,"lbm_writes_1-10_ms":2,"lbm_writes_lt_1ms":501,"reinsert_count":0,"update_count":2500}
I20260812 06:18:23.028223 11600 maintenance_manager.cc:419] P 44733cf2a3144939ad58ba0c26d58782: Scheduling FlushDeltaMemStoresOp(c820fcb7da67413fb643a69b5ffa8da8): perf score=3.181125
I20260812 06:18:23.040771 11515 maintenance_manager.cc:643] P 44733cf2a3144939ad58ba0c26d58782: FlushDeltaMemStoresOp(c820fcb7da67413fb643a69b5ffa8da8) complete. Timing: real 0.012s	user 0.003s	sys 0.007s Metrics: {"bytes_written":4512902,"delete_count":0,"lbm_write_time_us":4661,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:18:23.041234 11600 maintenance_manager.cc:419] P 44733cf2a3144939ad58ba0c26d58782: Scheduling FlushDeltaMemStoresOp(c820fcb7da67413fb643a69b5ffa8da8): perf score=2.188937
I20260812 06:18:23.050907 11515 maintenance_manager.cc:643] P 44733cf2a3144939ad58ba0c26d58782: FlushDeltaMemStoresOp(c820fcb7da67413fb643a69b5ffa8da8) complete. Timing: real 0.009s	user 0.008s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3472,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:18:23.051375 11600 maintenance_manager.cc:419] P 44733cf2a3144939ad58ba0c26d58782: Scheduling MajorDeltaCompactionOp(c820fcb7da67413fb643a69b5ffa8da8): perf score=1.000000
I20260812 06:18:23.235881 11515 maintenance_manager.cc:643] P 44733cf2a3144939ad58ba0c26d58782: MajorDeltaCompactionOp(c820fcb7da67413fb643a69b5ffa8da8) complete. Timing: real 0.184s	user 0.164s	sys 0.020s Metrics: {"cfile_cache_miss":733,"cfile_cache_miss_bytes":33020617,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":553,"lbm_read_time_us":13858,"lbm_reads_lt_1ms":773,"lbm_write_time_us":38577,"lbm_writes_lt_1ms":743,"mutex_wait_us":2,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":2048,"update_count":3500}
I20260812 06:18:23.236512 11600 maintenance_manager.cc:419] P 44733cf2a3144939ad58ba0c26d58782: Scheduling FlushDeltaMemStoresOp(c820fcb7da67413fb643a69b5ffa8da8): perf score=14.095187
I20260812 06:18:23.296811 11515 maintenance_manager.cc:643] P 44733cf2a3144939ad58ba0c26d58782: FlushDeltaMemStoresOp(c820fcb7da67413fb643a69b5ffa8da8) complete. Timing: real 0.060s	user 0.035s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":28102,"lbm_writes_1-10_ms":4,"lbm_writes_lt_1ms":399,"reinsert_count":0,"update_count":2000}
I20260812 06:18:23.297585 11600 maintenance_manager.cc:419] P 44733cf2a3144939ad58ba0c26d58782: Scheduling FlushDeltaMemStoresOp(c820fcb7da67413fb643a69b5ffa8da8): perf score=2.188937
I20260812 06:18:23.316612 11515 maintenance_manager.cc:643] P 44733cf2a3144939ad58ba0c26d58782: FlushDeltaMemStoresOp(c820fcb7da67413fb643a69b5ffa8da8) complete. Timing: real 0.019s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4511,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:23.317144 11600 maintenance_manager.cc:419] P 44733cf2a3144939ad58ba0c26d58782: Scheduling FlushDeltaMemStoresOp(c820fcb7da67413fb643a69b5ffa8da8): perf score=2.188937
I20260812 06:18:23.327445 11515 maintenance_manager.cc:643] P 44733cf2a3144939ad58ba0c26d58782: FlushDeltaMemStoresOp(c820fcb7da67413fb643a69b5ffa8da8) complete. Timing: real 0.010s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3927,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:23.328032 11600 maintenance_manager.cc:419] P 44733cf2a3144939ad58ba0c26d58782: Scheduling MajorDeltaCompactionOp(c820fcb7da67413fb643a69b5ffa8da8): perf score=1.000000
I20260812 06:18:23.490298 11515 maintenance_manager.cc:643] P 44733cf2a3144939ad58ba0c26d58782: MajorDeltaCompactionOp(c820fcb7da67413fb643a69b5ffa8da8) complete. Timing: real 0.162s	user 0.142s	sys 0.020s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28918214,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":233,"lbm_read_time_us":13157,"lbm_reads_lt_1ms":673,"lbm_write_time_us":31470,"lbm_writes_lt_1ms":643,"mutex_wait_us":47,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":17408,"update_count":3000}
I20260812 06:18:23.490988 11600 maintenance_manager.cc:419] P 44733cf2a3144939ad58ba0c26d58782: Scheduling FlushDeltaMemStoresOp(c820fcb7da67413fb643a69b5ffa8da8): perf score=14.095187
I20260812 06:18:23.540282 11515 maintenance_manager.cc:643] P 44733cf2a3144939ad58ba0c26d58782: FlushDeltaMemStoresOp(c820fcb7da67413fb643a69b5ffa8da8) complete. Timing: real 0.049s	user 0.027s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":19951,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:23.541035 11600 maintenance_manager.cc:419] P 44733cf2a3144939ad58ba0c26d58782: Scheduling FlushDeltaMemStoresOp(c820fcb7da67413fb643a69b5ffa8da8): perf score=2.188937
I20260812 06:18:23.554940 11515 maintenance_manager.cc:643] P 44733cf2a3144939ad58ba0c26d58782: FlushDeltaMemStoresOp(c820fcb7da67413fb643a69b5ffa8da8) complete. Timing: real 0.014s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4875,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:23.555446 11600 maintenance_manager.cc:419] P 44733cf2a3144939ad58ba0c26d58782: Scheduling MajorDeltaCompactionOp(c820fcb7da67413fb643a69b5ffa8da8): perf score=1.000000
I20260812 06:18:23.709242 11515 maintenance_manager.cc:643] P 44733cf2a3144939ad58ba0c26d58782: MajorDeltaCompactionOp(c820fcb7da67413fb643a69b5ffa8da8) complete. Timing: real 0.153s	user 0.084s	sys 0.067s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24815683,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1684,"lbm_read_time_us":9736,"lbm_reads_lt_1ms":564,"lbm_write_time_us":29827,"lbm_writes_lt_1ms":543,"mutex_wait_us":369,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":2500}
I20260812 06:18:23.709954 11600 maintenance_manager.cc:419] P 44733cf2a3144939ad58ba0c26d58782: Scheduling FlushDeltaMemStoresOp(c820fcb7da67413fb643a69b5ffa8da8): perf score=14.095187
I20260812 06:18:23.755091 11515 maintenance_manager.cc:643] P 44733cf2a3144939ad58ba0c26d58782: FlushDeltaMemStoresOp(c820fcb7da67413fb643a69b5ffa8da8) complete. Timing: real 0.045s	user 0.031s	sys 0.012s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":19566,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:23.755594 11600 maintenance_manager.cc:419] P 44733cf2a3144939ad58ba0c26d58782: Scheduling MajorDeltaCompactionOp(c820fcb7da67413fb643a69b5ffa8da8): perf score=1.000000
I20260812 06:18:23.926290 11515 maintenance_manager.cc:643] P 44733cf2a3144939ad58ba0c26d58782: MajorDeltaCompactionOp(c820fcb7da67413fb643a69b5ffa8da8) complete. Timing: real 0.170s	user 0.098s	sys 0.060s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20713153,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":1311,"lbm_read_time_us":10751,"lbm_reads_lt_1ms":467,"lbm_write_time_us":25704,"lbm_writes_lt_1ms":443,"mutex_wait_us":417,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11520,"update_count":2000}
I20260812 06:18:23.927001 11600 maintenance_manager.cc:419] P 44733cf2a3144939ad58ba0c26d58782: Scheduling FlushDeltaMemStoresOp(c820fcb7da67413fb643a69b5ffa8da8): perf score=14.095187
I20260812 06:18:23.981958 11515 maintenance_manager.cc:643] P 44733cf2a3144939ad58ba0c26d58782: FlushDeltaMemStoresOp(c820fcb7da67413fb643a69b5ffa8da8) complete. Timing: real 0.055s	user 0.043s	sys 0.008s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":23562,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:18:23.982506 11600 maintenance_manager.cc:419] P 44733cf2a3144939ad58ba0c26d58782: Scheduling FlushDeltaMemStoresOp(c820fcb7da67413fb643a69b5ffa8da8): perf score=2.188937
I20260812 06:18:23.993598 11515 maintenance_manager.cc:643] P 44733cf2a3144939ad58ba0c26d58782: FlushDeltaMemStoresOp(c820fcb7da67413fb643a69b5ffa8da8) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4008,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:23.994086 11600 maintenance_manager.cc:419] P 44733cf2a3144939ad58ba0c26d58782: Scheduling FlushMRSOp(c820fcb7da67413fb643a69b5ffa8da8): perf score=1.000000
I20260812 06:18:24.029151 11515 maintenance_manager.cc:643] P 44733cf2a3144939ad58ba0c26d58782: FlushMRSOp(c820fcb7da67413fb643a69b5ffa8da8) complete. Timing: real 0.035s	user 0.030s	sys 0.004s Metrics: {"bytes_written":1152510,"cfile_init":1,"dirs.queue_time_us":82,"dirs.run_cpu_time_us":241,"dirs.run_wall_time_us":1559,"drs_written":1,"lbm_read_time_us":63,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2035,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":28}
I20260812 06:18:24.029875 11600 maintenance_manager.cc:419] P 44733cf2a3144939ad58ba0c26d58782: Scheduling LogGCOp(c820fcb7da67413fb643a69b5ffa8da8): free 116849714 bytes of WAL
I20260812 06:18:24.030151 11515 log_reader.cc:385] T c820fcb7da67413fb643a69b5ffa8da8: removed 12 log segments from log reader
I20260812 06:18:24.030224 11515 log.cc:1079] T c820fcb7da67413fb643a69b5ffa8da8 P 44733cf2a3144939ad58ba0c26d58782: Deleting log segment in path: /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515494136637-11097-0/minicluster-data/ts-0-root/wals/c820fcb7da67413fb643a69b5ffa8da8/wal-000000026 (ops 127-131)
I20260812 06:18:24.030267 11515 log.cc:1079] T c820fcb7da67413fb643a69b5ffa8da8 P 44733cf2a3144939ad58ba0c26d58782: Deleting log segment in path: /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515494136637-11097-0/minicluster-data/ts-0-root/wals/c820fcb7da67413fb643a69b5ffa8da8/wal-000000027 (ops 132-136)
I20260812 06:18:24.030300 11515 log.cc:1079] T c820fcb7da67413fb643a69b5ffa8da8 P 44733cf2a3144939ad58ba0c26d58782: Deleting log segment in path: /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515494136637-11097-0/minicluster-data/ts-0-root/wals/c820fcb7da67413fb643a69b5ffa8da8/wal-000000028 (ops 137-141)
I20260812 06:18:24.030332 11515 log.cc:1079] T c820fcb7da67413fb643a69b5ffa8da8 P 44733cf2a3144939ad58ba0c26d58782: Deleting log segment in path: /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515494136637-11097-0/minicluster-data/ts-0-root/wals/c820fcb7da67413fb643a69b5ffa8da8/wal-000000029 (ops 142-146)
I20260812 06:18:24.030356 11515 log.cc:1079] T c820fcb7da67413fb643a69b5ffa8da8 P 44733cf2a3144939ad58ba0c26d58782: Deleting log segment in path: /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515494136637-11097-0/minicluster-data/ts-0-root/wals/c820fcb7da67413fb643a69b5ffa8da8/wal-000000030 (ops 147-150)
I20260812 06:18:24.030380 11515 log.cc:1079] T c820fcb7da67413fb643a69b5ffa8da8 P 44733cf2a3144939ad58ba0c26d58782: Deleting log segment in path: /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515494136637-11097-0/minicluster-data/ts-0-root/wals/c820fcb7da67413fb643a69b5ffa8da8/wal-000000031 (ops 151-155)
I20260812 06:18:24.030414 11515 log.cc:1079] T c820fcb7da67413fb643a69b5ffa8da8 P 44733cf2a3144939ad58ba0c26d58782: Deleting log segment in path: /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515494136637-11097-0/minicluster-data/ts-0-root/wals/c820fcb7da67413fb643a69b5ffa8da8/wal-000000032 (ops 156-160)
I20260812 06:18:24.030442 11515 log.cc:1079] T c820fcb7da67413fb643a69b5ffa8da8 P 44733cf2a3144939ad58ba0c26d58782: Deleting log segment in path: /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515494136637-11097-0/minicluster-data/ts-0-root/wals/c820fcb7da67413fb643a69b5ffa8da8/wal-000000033 (ops 161-164)
I20260812 06:18:24.030471 11515 log.cc:1079] T c820fcb7da67413fb643a69b5ffa8da8 P 44733cf2a3144939ad58ba0c26d58782: Deleting log segment in path: /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515494136637-11097-0/minicluster-data/ts-0-root/wals/c820fcb7da67413fb643a69b5ffa8da8/wal-000000034 (ops 165-169)
I20260812 06:18:24.030498 11515 log.cc:1079] T c820fcb7da67413fb643a69b5ffa8da8 P 44733cf2a3144939ad58ba0c26d58782: Deleting log segment in path: /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515494136637-11097-0/minicluster-data/ts-0-root/wals/c820fcb7da67413fb643a69b5ffa8da8/wal-000000035 (ops 170-174)
I20260812 06:18:24.030524 11515 log.cc:1079] T c820fcb7da67413fb643a69b5ffa8da8 P 44733cf2a3144939ad58ba0c26d58782: Deleting log segment in path: /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515494136637-11097-0/minicluster-data/ts-0-root/wals/c820fcb7da67413fb643a69b5ffa8da8/wal-000000036 (ops 175-178)
I20260812 06:18:24.030553 11515 log.cc:1079] T c820fcb7da67413fb643a69b5ffa8da8 P 44733cf2a3144939ad58ba0c26d58782: Deleting log segment in path: /tmp/dist-test-taskwNO3i0/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515494136637-11097-0/minicluster-data/ts-0-root/wals/c820fcb7da67413fb643a69b5ffa8da8/wal-000000037 (ops 179-183)
I20260812 06:18:24.059276 11515 maintenance_manager.cc:643] P 44733cf2a3144939ad58ba0c26d58782: LogGCOp(c820fcb7da67413fb643a69b5ffa8da8) complete. Timing: real 0.029s	user 0.000s	sys 0.027s Metrics: {}
I20260812 06:18:24.059813 11600 maintenance_manager.cc:419] P 44733cf2a3144939ad58ba0c26d58782: Scheduling UndoDeltaBlockGCOp(c820fcb7da67413fb643a69b5ffa8da8): 446 bytes on disk
I20260812 06:18:24.060464 11515 maintenance_manager.cc:643] P 44733cf2a3144939ad58ba0c26d58782: UndoDeltaBlockGCOp(c820fcb7da67413fb643a69b5ffa8da8) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":118,"lbm_reads_lt_1ms":4}
I20260812 06:18:24.061318 11600 maintenance_manager.cc:419] P 44733cf2a3144939ad58ba0c26d58782: Scheduling FlushDeltaMemStoresOp(c820fcb7da67413fb643a69b5ffa8da8): perf score=2.188937
I20260812 06:18:24.086551 11515 maintenance_manager.cc:643] P 44733cf2a3144939ad58ba0c26d58782: FlushDeltaMemStoresOp(c820fcb7da67413fb643a69b5ffa8da8) complete. Timing: real 0.025s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5782,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:24.087083 11600 maintenance_manager.cc:419] P 44733cf2a3144939ad58ba0c26d58782: Scheduling FlushDeltaMemStoresOp(c820fcb7da67413fb643a69b5ffa8da8): perf score=2.188937
I20260812 06:18:24.097868 11515 maintenance_manager.cc:643] P 44733cf2a3144939ad58ba0c26d58782: FlushDeltaMemStoresOp(c820fcb7da67413fb643a69b5ffa8da8) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4065,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:24.098332 11600 maintenance_manager.cc:419] P 44733cf2a3144939ad58ba0c26d58782: Scheduling MajorDeltaCompactionOp(c820fcb7da67413fb643a69b5ffa8da8): perf score=1.000000
I20260812 06:18:24.337018 11515 maintenance_manager.cc:643] P 44733cf2a3144939ad58ba0c26d58782: MajorDeltaCompactionOp(c820fcb7da67413fb643a69b5ffa8da8) complete. Timing: real 0.239s	user 0.158s	sys 0.076s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":33020743,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":591,"lbm_read_time_us":14992,"lbm_reads_lt_1ms":774,"lbm_write_time_us":38817,"lbm_writes_lt_1ms":743,"mutex_wait_us":95,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":9984,"thread_start_us":84,"threads_started":1,"update_count":3500}
I20260812 06:18:24.337867 11600 maintenance_manager.cc:419] P 44733cf2a3144939ad58ba0c26d58782: Scheduling FlushDeltaMemStoresOp(c820fcb7da67413fb643a69b5ffa8da8): perf score=18.063937
I20260812 06:18:24.406800 11515 maintenance_manager.cc:643] P 44733cf2a3144939ad58ba0c26d58782: FlushDeltaMemStoresOp(c820fcb7da67413fb643a69b5ffa8da8) complete. Timing: real 0.068s	user 0.035s	sys 0.020s Metrics: {"bytes_written":20512315,"delete_count":0,"lbm_write_time_us":25708,"lbm_writes_lt_1ms":503,"reinsert_count":0,"update_count":2500}
I20260812 06:18:24.407289 11600 maintenance_manager.cc:419] P 44733cf2a3144939ad58ba0c26d58782: Scheduling FlushDeltaMemStoresOp(c820fcb7da67413fb643a69b5ffa8da8): perf score=2.188937
I20260812 06:18:24.418082 11515 maintenance_manager.cc:643] P 44733cf2a3144939ad58ba0c26d58782: FlushDeltaMemStoresOp(c820fcb7da67413fb643a69b5ffa8da8) complete. Timing: real 0.011s	user 0.001s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4250,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:18:24.418556 11600 maintenance_manager.cc:419] P 44733cf2a3144939ad58ba0c26d58782: Scheduling MajorDeltaCompactionOp(c820fcb7da67413fb643a69b5ffa8da8): perf score=1.000000
I20260812 06:18:24.452355 11097 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.756s	user 1.790s	sys 0.147s
I20260812 06:18:24.534541 11097 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.082s	user 0.003s	sys 0.000s
I20260812 06:18:24.535166 11097 tablet_server.cc:179] TabletServer@127.10.214.65:0 shutting down...
I20260812 06:18:24.593971 11515 maintenance_manager.cc:643] P 44733cf2a3144939ad58ba0c26d58782: MajorDeltaCompactionOp(c820fcb7da67413fb643a69b5ffa8da8) complete. Timing: real 0.175s	user 0.119s	sys 0.056s Metrics: {"cfile_cache_miss":632,"cfile_cache_miss_bytes":28918097,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":368,"lbm_read_time_us":14144,"lbm_reads_lt_1ms":668,"lbm_write_time_us":29410,"lbm_writes_lt_1ms":643,"mutex_wait_us":85,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":11264,"update_count":3000}
I20260812 06:18:24.594882 11097 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:18:24.595219 11097 tablet_replica.cc:333] T c820fcb7da67413fb643a69b5ffa8da8 P 44733cf2a3144939ad58ba0c26d58782: stopping tablet replica
I20260812 06:18:24.595363 11097 raft_consensus.cc:2243] T c820fcb7da67413fb643a69b5ffa8da8 P 44733cf2a3144939ad58ba0c26d58782 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:24.595572 11097 raft_consensus.cc:2272] T c820fcb7da67413fb643a69b5ffa8da8 P 44733cf2a3144939ad58ba0c26d58782 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:24.600363 11097 tablet_server.cc:196] TabletServer@127.10.214.65:0 shutdown complete.
I20260812 06:18:24.646571 11097 master.cc:562] Master@127.10.214.126:46599 shutting down...
I20260812 06:18:24.649953 11097 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 8f2686ee72bf433493870404e6fe313d [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:18:24.650132 11097 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 8f2686ee72bf433493870404e6fe313d [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:18:24.650184 11097 tablet_replica.cc:333] T 00000000000000000000000000000000 P 8f2686ee72bf433493870404e6fe313d: stopping tablet replica
I20260812 06:18:24.662585 11097 master.cc:584] Master@127.10.214.126:46599 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5327 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (10615 ms total)

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