[==========] Running 2 tests from 1 test suite.
[----------] Global test environment set-up.
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0
WARNING: Logging before InitGoogleLogging() is written to STDERR
I20260812 06:19:22.560102  2253 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.2.51.126:42649
I20260812 06:19:22.561122  2253 env_posix.cc:2285] Not raising this process' open files per process limit of 1048576; it is already as high as it can go
I20260812 06:19:22.561715  2253 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:22.567809  2262 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:22.568030  2259 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:22.568060  2258 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:22.567937  2253 server_base.cc:1061] running on GCE node
I20260812 06:19:22.568572  2253 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:22.568686  2253 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:22.568768  2253 hybrid_clock.cc:648] HybridClock initialized: now 1786515562568750 us; error 0 us; skew 500 ppm
I20260812 06:19:22.570623  2253 webserver.cc:533] Webserver started at http://127.2.51.126:46081/ using document root <none> and password file <none>
I20260812 06:19:22.571180  2253 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:22.571264  2253 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:22.571506  2253 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:22.573217  2253 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515562549282-2253-0/minicluster-data/master-0-root/instance:
uuid: "3d93989b20fc43189d5214036de907f8"
format_stamp: "Formatted at 2026-08-12 06:19:22 on dist-test-slave-10pc"
I20260812 06:19:22.576653  2253 fs_manager.cc:696] Time spent creating directory manager: real 0.003s	user 0.004s	sys 0.000s
I20260812 06:19:22.578763  2267 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:22.579778  2253 fs_manager.cc:730] Time spent opening block manager: real 0.002s	user 0.002s	sys 0.000s
I20260812 06:19:22.579931  2253 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515562549282-2253-0/minicluster-data/master-0-root
uuid: "3d93989b20fc43189d5214036de907f8"
format_stamp: "Formatted at 2026-08-12 06:19:22 on dist-test-slave-10pc"
I20260812 06:19:22.580040  2253 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515562549282-2253-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515562549282-2253-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515562549282-2253-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:22.616024  2253 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:22.616835  2253 env_posix.cc:2285] Not raising this process' running threads per effective uid limit of 18446744073709551615; it is already as high as it can go
I20260812 06:19:22.617036  2253 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:22.624502  2253 rpc_server.cc:307] RPC server started. Bound to: 127.2.51.126:42649
I20260812 06:19:22.624544  2330 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.2.51.126:42649 every 8 connection(s)
I20260812 06:19:22.626708  2331 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:22.632105  2331 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 3d93989b20fc43189d5214036de907f8: Bootstrap starting.
I20260812 06:19:22.634476  2331 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 3d93989b20fc43189d5214036de907f8: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:22.635385  2331 log.cc:826] T 00000000000000000000000000000000 P 3d93989b20fc43189d5214036de907f8: Log is configured to *not* fsync() on all Append() calls
I20260812 06:19:22.637125  2331 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 3d93989b20fc43189d5214036de907f8: No bootstrap required, opened a new log
I20260812 06:19:22.639822  2331 raft_consensus.cc:359] T 00000000000000000000000000000000 P 3d93989b20fc43189d5214036de907f8 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3d93989b20fc43189d5214036de907f8" member_type: VOTER }
I20260812 06:19:22.639982  2331 raft_consensus.cc:385] T 00000000000000000000000000000000 P 3d93989b20fc43189d5214036de907f8 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:22.640054  2331 raft_consensus.cc:740] T 00000000000000000000000000000000 P 3d93989b20fc43189d5214036de907f8 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 3d93989b20fc43189d5214036de907f8, State: Initialized, Role: FOLLOWER
I20260812 06:19:22.640676  2331 consensus_queue.cc:260] T 00000000000000000000000000000000 P 3d93989b20fc43189d5214036de907f8 [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: "3d93989b20fc43189d5214036de907f8" member_type: VOTER }
I20260812 06:19:22.640837  2331 raft_consensus.cc:399] T 00000000000000000000000000000000 P 3d93989b20fc43189d5214036de907f8 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:22.640918  2331 raft_consensus.cc:493] T 00000000000000000000000000000000 P 3d93989b20fc43189d5214036de907f8 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:22.641088  2331 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 3d93989b20fc43189d5214036de907f8 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:22.641877  2331 raft_consensus.cc:515] T 00000000000000000000000000000000 P 3d93989b20fc43189d5214036de907f8 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3d93989b20fc43189d5214036de907f8" member_type: VOTER }
I20260812 06:19:22.642381  2331 leader_election.cc:304] T 00000000000000000000000000000000 P 3d93989b20fc43189d5214036de907f8 [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: 3d93989b20fc43189d5214036de907f8; no voters: 
I20260812 06:19:22.642797  2331 leader_election.cc:290] T 00000000000000000000000000000000 P 3d93989b20fc43189d5214036de907f8 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:22.643206  2337 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 3d93989b20fc43189d5214036de907f8 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:22.643436  2337 raft_consensus.cc:697] T 00000000000000000000000000000000 P 3d93989b20fc43189d5214036de907f8 [term 1 LEADER]: Becoming Leader. State: Replica: 3d93989b20fc43189d5214036de907f8, State: Running, Role: LEADER
I20260812 06:19:22.643851  2331 sys_catalog.cc:565] T 00000000000000000000000000000000 P 3d93989b20fc43189d5214036de907f8 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:22.643849  2337 consensus_queue.cc:237] T 00000000000000000000000000000000 P 3d93989b20fc43189d5214036de907f8 [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: "3d93989b20fc43189d5214036de907f8" member_type: VOTER }
I20260812 06:19:22.646009  2338 sys_catalog.cc:455] T 00000000000000000000000000000000 P 3d93989b20fc43189d5214036de907f8 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "3d93989b20fc43189d5214036de907f8" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3d93989b20fc43189d5214036de907f8" member_type: VOTER } }
I20260812 06:19:22.646144  2338 sys_catalog.cc:458] T 00000000000000000000000000000000 P 3d93989b20fc43189d5214036de907f8 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:22.646529  2253 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:22.646687  2353 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:22.646740  2335 sys_catalog.cc:455] T 00000000000000000000000000000000 P 3d93989b20fc43189d5214036de907f8 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 3d93989b20fc43189d5214036de907f8. Latest consensus state: current_term: 1 leader_uuid: "3d93989b20fc43189d5214036de907f8" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "3d93989b20fc43189d5214036de907f8" member_type: VOTER } }
I20260812 06:19:22.646816  2335 sys_catalog.cc:458] T 00000000000000000000000000000000 P 3d93989b20fc43189d5214036de907f8 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:22.649581  2353 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:22.655414  2353 catalog_manager.cc:1383] Generated new cluster ID: 9540a74fbf434b829a54dd2e1ca73348
I20260812 06:19:22.655557  2353 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:22.667655  2353 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:22.668839  2353 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:22.682355  2353 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 3d93989b20fc43189d5214036de907f8: Generated new TSK 0
I20260812 06:19:22.683166  2353 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:22.711687  2253 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:22.714695  2358 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:22.714781  2362 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:22.714854  2359 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:22.715022  2253 server_base.cc:1061] running on GCE node
I20260812 06:19:22.715507  2253 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:22.715567  2253 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:22.715592  2253 hybrid_clock.cc:648] HybridClock initialized: now 1786515562715592 us; error 0 us; skew 500 ppm
I20260812 06:19:22.716604  2253 webserver.cc:533] Webserver started at http://127.2.51.65:43263/ using document root <none> and password file <none>
I20260812 06:19:22.716778  2253 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:22.716840  2253 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:22.716919  2253 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:22.717384  2253 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515562549282-2253-0/minicluster-data/ts-0-root/instance:
uuid: "8824592e240b4a13a253cd594bec77a9"
format_stamp: "Formatted at 2026-08-12 06:19:22 on dist-test-slave-10pc"
I20260812 06:19:22.719269  2253 fs_manager.cc:696] Time spent creating directory manager: real 0.002s	user 0.000s	sys 0.002s
I20260812 06:19:22.720386  2367 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:22.720702  2253 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.000s	sys 0.001s
I20260812 06:19:22.720784  2253 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515562549282-2253-0/minicluster-data/ts-0-root
uuid: "8824592e240b4a13a253cd594bec77a9"
format_stamp: "Formatted at 2026-08-12 06:19:22 on dist-test-slave-10pc"
I20260812 06:19:22.720849  2253 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515562549282-2253-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515562549282-2253-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515562549282-2253-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:22.734298  2253 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:22.734887  2253 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:22.735452  2253 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:22.736510  2253 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:22.736579  2253 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:22.736647  2253 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:22.736668  2253 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:22.743515  2253 rpc_server.cc:307] RPC server started. Bound to: 127.2.51.65:42641
I20260812 06:19:22.743613  2437 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.2.51.65:42641 every 8 connection(s)
I20260812 06:19:22.759575  2438 heartbeater.cc:344] Connected to a master server at 127.2.51.126:42649
I20260812 06:19:22.759883  2438 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:22.760403  2438 heartbeater.cc:507] Master 127.2.51.126:42649 requested a full tablet report, sending...
I20260812 06:19:22.761948  2286 ts_manager.cc:194] Registered new tserver with Master: 8824592e240b4a13a253cd594bec77a9 (127.2.51.65:42641)
I20260812 06:19:22.763108  2286 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:34258
I20260812 06:19:22.763350  2253 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.019169416s
I20260812 06:19:22.773098  2286 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:34262:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:19:22.787245  2396 tablet_service.cc:1511] Processing CreateTablet for tablet d39a7e3dd461408784e0221fffc31232 (DEFAULT_TABLE table=heavy-update-compaction-test [id=20919bf0a52f4ff19bd2ee3ced5c3cb7]), partition=
I20260812 06:19:22.787735  2396 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet d39a7e3dd461408784e0221fffc31232. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:22.790120  2452 tablet_bootstrap.cc:492] T d39a7e3dd461408784e0221fffc31232 P 8824592e240b4a13a253cd594bec77a9: Bootstrap starting.
I20260812 06:19:22.791612  2452 tablet_bootstrap.cc:654] T d39a7e3dd461408784e0221fffc31232 P 8824592e240b4a13a253cd594bec77a9: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:22.792795  2452 tablet_bootstrap.cc:492] T d39a7e3dd461408784e0221fffc31232 P 8824592e240b4a13a253cd594bec77a9: No bootstrap required, opened a new log
I20260812 06:19:22.792908  2452 ts_tablet_manager.cc:1403] T d39a7e3dd461408784e0221fffc31232 P 8824592e240b4a13a253cd594bec77a9: Time spent bootstrapping tablet: real 0.003s	user 0.002s	sys 0.000s
I20260812 06:19:22.793362  2452 raft_consensus.cc:359] T d39a7e3dd461408784e0221fffc31232 P 8824592e240b4a13a253cd594bec77a9 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8824592e240b4a13a253cd594bec77a9" member_type: VOTER last_known_addr { host: "127.2.51.65" port: 42641 } }
I20260812 06:19:22.793463  2452 raft_consensus.cc:385] T d39a7e3dd461408784e0221fffc31232 P 8824592e240b4a13a253cd594bec77a9 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:22.793486  2452 raft_consensus.cc:740] T d39a7e3dd461408784e0221fffc31232 P 8824592e240b4a13a253cd594bec77a9 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 8824592e240b4a13a253cd594bec77a9, State: Initialized, Role: FOLLOWER
I20260812 06:19:22.793684  2452 consensus_queue.cc:260] T d39a7e3dd461408784e0221fffc31232 P 8824592e240b4a13a253cd594bec77a9 [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: "8824592e240b4a13a253cd594bec77a9" member_type: VOTER last_known_addr { host: "127.2.51.65" port: 42641 } }
I20260812 06:19:22.793757  2452 raft_consensus.cc:399] T d39a7e3dd461408784e0221fffc31232 P 8824592e240b4a13a253cd594bec77a9 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:22.793828  2452 raft_consensus.cc:493] T d39a7e3dd461408784e0221fffc31232 P 8824592e240b4a13a253cd594bec77a9 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:22.793885  2452 raft_consensus.cc:3060] T d39a7e3dd461408784e0221fffc31232 P 8824592e240b4a13a253cd594bec77a9 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:22.794761  2452 raft_consensus.cc:515] T d39a7e3dd461408784e0221fffc31232 P 8824592e240b4a13a253cd594bec77a9 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8824592e240b4a13a253cd594bec77a9" member_type: VOTER last_known_addr { host: "127.2.51.65" port: 42641 } }
I20260812 06:19:22.794912  2452 leader_election.cc:304] T d39a7e3dd461408784e0221fffc31232 P 8824592e240b4a13a253cd594bec77a9 [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: 8824592e240b4a13a253cd594bec77a9; no voters: 
I20260812 06:19:22.795135  2452 leader_election.cc:290] T d39a7e3dd461408784e0221fffc31232 P 8824592e240b4a13a253cd594bec77a9 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:22.795238  2454 raft_consensus.cc:2804] T d39a7e3dd461408784e0221fffc31232 P 8824592e240b4a13a253cd594bec77a9 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:22.795496  2454 raft_consensus.cc:697] T d39a7e3dd461408784e0221fffc31232 P 8824592e240b4a13a253cd594bec77a9 [term 1 LEADER]: Becoming Leader. State: Replica: 8824592e240b4a13a253cd594bec77a9, State: Running, Role: LEADER
I20260812 06:19:22.795605  2452 ts_tablet_manager.cc:1434] T d39a7e3dd461408784e0221fffc31232 P 8824592e240b4a13a253cd594bec77a9: Time spent starting tablet: real 0.003s	user 0.000s	sys 0.003s
I20260812 06:19:22.795877  2438 heartbeater.cc:499] Master 127.2.51.126:42649 was elected leader, sending a full tablet report...
I20260812 06:19:22.795725  2454 consensus_queue.cc:237] T d39a7e3dd461408784e0221fffc31232 P 8824592e240b4a13a253cd594bec77a9 [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: "8824592e240b4a13a253cd594bec77a9" member_type: VOTER last_known_addr { host: "127.2.51.65" port: 42641 } }
I20260812 06:19:22.799052  2286 catalog_manager.cc:5719] T d39a7e3dd461408784e0221fffc31232 P 8824592e240b4a13a253cd594bec77a9 reported cstate change: term changed from 0 to 1, leader changed from <none> to 8824592e240b4a13a253cd594bec77a9 (127.2.51.65). New cstate: current_term: 1 leader_uuid: "8824592e240b4a13a253cd594bec77a9" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "8824592e240b4a13a253cd594bec77a9" member_type: VOTER last_known_addr { host: "127.2.51.65" port: 42641 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:22.867509  2253 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.059s	user 0.028s	sys 0.000s
I20260812 06:19:22.994702  2439 maintenance_manager.cc:419] P 8824592e240b4a13a253cd594bec77a9: Scheduling FlushMRSOp(d39a7e3dd461408784e0221fffc31232): perf score=17.070565
I20260812 06:19:23.175441  2372 maintenance_manager.cc:643] P 8824592e240b4a13a253cd594bec77a9: FlushMRSOp(d39a7e3dd461408784e0221fffc31232) complete. Timing: real 0.180s	user 0.126s	sys 0.047s Metrics: {"bytes_written":12307490,"cfile_init":1,"compiler_manager_pool.queue_time_us":430,"delete_count":0,"dirs.queue_time_us":41,"dirs.run_cpu_time_us":196,"dirs.run_wall_time_us":2524,"drs_written":1,"lbm_read_time_us":117,"lbm_reads_lt_1ms":4,"lbm_write_time_us":48813,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":756,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"thread_start_us":101,"threads_started":1,"update_count":1500}
I20260812 06:19:23.176767  2439 maintenance_manager.cc:419] P 8824592e240b4a13a253cd594bec77a9: Scheduling LogGCOp(d39a7e3dd461408784e0221fffc31232): free 20743880 bytes of WAL
I20260812 06:19:23.177078  2372 log_reader.cc:385] T d39a7e3dd461408784e0221fffc31232: removed 2 log segments from log reader
I20260812 06:19:23.177140  2372 log.cc:1079] T d39a7e3dd461408784e0221fffc31232 P 8824592e240b4a13a253cd594bec77a9: Deleting log segment in path: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515562549282-2253-0/minicluster-data/ts-0-root/wals/d39a7e3dd461408784e0221fffc31232/wal-000000001 (ops 1-6)
I20260812 06:19:23.177199  2372 log.cc:1079] T d39a7e3dd461408784e0221fffc31232 P 8824592e240b4a13a253cd594bec77a9: Deleting log segment in path: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515562549282-2253-0/minicluster-data/ts-0-root/wals/d39a7e3dd461408784e0221fffc31232/wal-000000002 (ops 7-11)
I20260812 06:19:23.183096  2372 maintenance_manager.cc:643] P 8824592e240b4a13a253cd594bec77a9: LogGCOp(d39a7e3dd461408784e0221fffc31232) complete. Timing: real 0.006s	user 0.000s	sys 0.004s Metrics: {}
I20260812 06:19:23.183513  2439 maintenance_manager.cc:419] P 8824592e240b4a13a253cd594bec77a9: Scheduling FlushDeltaMemStoresOp(d39a7e3dd461408784e0221fffc31232): perf score=2.188937
I20260812 06:19:23.217674  2372 maintenance_manager.cc:643] P 8824592e240b4a13a253cd594bec77a9: FlushDeltaMemStoresOp(d39a7e3dd461408784e0221fffc31232) complete. Timing: real 0.034s	user 0.017s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6109,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:23.218214  2439 maintenance_manager.cc:419] P 8824592e240b4a13a253cd594bec77a9: Scheduling UndoDeltaBlockGCOp(d39a7e3dd461408784e0221fffc31232): 16411392 bytes on disk
I20260812 06:19:23.218838  2372 maintenance_manager.cc:643] P 8824592e240b4a13a253cd594bec77a9: UndoDeltaBlockGCOp(d39a7e3dd461408784e0221fffc31232) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":75,"lbm_reads_lt_1ms":4}
I20260812 06:19:23.219250  2439 maintenance_manager.cc:419] P 8824592e240b4a13a253cd594bec77a9: Scheduling FlushDeltaMemStoresOp(d39a7e3dd461408784e0221fffc31232): perf score=2.188937
I20260812 06:19:23.233187  2372 maintenance_manager.cc:643] P 8824592e240b4a13a253cd594bec77a9: FlushDeltaMemStoresOp(d39a7e3dd461408784e0221fffc31232) complete. Timing: real 0.014s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5514,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:23.233701  2439 maintenance_manager.cc:419] P 8824592e240b4a13a253cd594bec77a9: Scheduling MajorDeltaCompactionOp(d39a7e3dd461408784e0221fffc31232): perf score=1.000000
I20260812 06:19:23.403224  2372 maintenance_manager.cc:643] P 8824592e240b4a13a253cd594bec77a9: MajorDeltaCompactionOp(d39a7e3dd461408784e0221fffc31232) complete. Timing: real 0.169s	user 0.093s	sys 0.076s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774808,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":622,"lbm_read_time_us":11024,"lbm_reads_lt_1ms":569,"lbm_write_time_us":29363,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"thread_start_us":335,"threads_started":5,"update_count":2500}
I20260812 06:19:23.403805  2439 maintenance_manager.cc:419] P 8824592e240b4a13a253cd594bec77a9: Scheduling FlushDeltaMemStoresOp(d39a7e3dd461408784e0221fffc31232): perf score=10.126437
I20260812 06:19:23.450842  2372 maintenance_manager.cc:643] P 8824592e240b4a13a253cd594bec77a9: FlushDeltaMemStoresOp(d39a7e3dd461408784e0221fffc31232) complete. Timing: real 0.047s	user 0.036s	sys 0.007s Metrics: {"bytes_written":12307493,"delete_count":0,"lbm_write_time_us":19784,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:23.451373  2439 maintenance_manager.cc:419] P 8824592e240b4a13a253cd594bec77a9: Scheduling FlushDeltaMemStoresOp(d39a7e3dd461408784e0221fffc31232): perf score=2.188937
I20260812 06:19:23.463320  2372 maintenance_manager.cc:643] P 8824592e240b4a13a253cd594bec77a9: FlushDeltaMemStoresOp(d39a7e3dd461408784e0221fffc31232) complete. Timing: real 0.012s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4540,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:23.463943  2439 maintenance_manager.cc:419] P 8824592e240b4a13a253cd594bec77a9: Scheduling MajorDeltaCompactionOp(d39a7e3dd461408784e0221fffc31232): perf score=1.000000
I20260812 06:19:23.590806  2372 maintenance_manager.cc:643] P 8824592e240b4a13a253cd594bec77a9: MajorDeltaCompactionOp(d39a7e3dd461408784e0221fffc31232) complete. Timing: real 0.127s	user 0.099s	sys 0.027s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672280,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":155,"lbm_read_time_us":9557,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24390,"lbm_writes_lt_1ms":443,"mutex_wait_us":47,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9728,"update_count":2000}
I20260812 06:19:23.591387  2439 maintenance_manager.cc:419] P 8824592e240b4a13a253cd594bec77a9: Scheduling FlushDeltaMemStoresOp(d39a7e3dd461408784e0221fffc31232): perf score=10.126437
I20260812 06:19:23.633404  2372 maintenance_manager.cc:643] P 8824592e240b4a13a253cd594bec77a9: FlushDeltaMemStoresOp(d39a7e3dd461408784e0221fffc31232) complete. Timing: real 0.042s	user 0.024s	sys 0.011s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":15515,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:23.633863  2439 maintenance_manager.cc:419] P 8824592e240b4a13a253cd594bec77a9: Scheduling FlushDeltaMemStoresOp(d39a7e3dd461408784e0221fffc31232): perf score=2.188937
I20260812 06:19:23.644556  2372 maintenance_manager.cc:643] P 8824592e240b4a13a253cd594bec77a9: FlushDeltaMemStoresOp(d39a7e3dd461408784e0221fffc31232) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4155,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:23.645059  2439 maintenance_manager.cc:419] P 8824592e240b4a13a253cd594bec77a9: Scheduling MajorDeltaCompactionOp(d39a7e3dd461408784e0221fffc31232): perf score=1.000000
I20260812 06:19:23.775254  2372 maintenance_manager.cc:643] P 8824592e240b4a13a253cd594bec77a9: MajorDeltaCompactionOp(d39a7e3dd461408784e0221fffc31232) complete. Timing: real 0.130s	user 0.096s	sys 0.032s 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":589,"lbm_read_time_us":7919,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25846,"lbm_writes_lt_1ms":443,"mutex_wait_us":283,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:19:23.775892  2439 maintenance_manager.cc:419] P 8824592e240b4a13a253cd594bec77a9: Scheduling FlushDeltaMemStoresOp(d39a7e3dd461408784e0221fffc31232): perf score=10.126437
I20260812 06:19:23.823261  2372 maintenance_manager.cc:643] P 8824592e240b4a13a253cd594bec77a9: FlushDeltaMemStoresOp(d39a7e3dd461408784e0221fffc31232) complete. Timing: real 0.047s	user 0.031s	sys 0.008s Metrics: {"bytes_written":12307492,"delete_count":0,"lbm_write_time_us":18548,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:23.823714  2439 maintenance_manager.cc:419] P 8824592e240b4a13a253cd594bec77a9: Scheduling FlushDeltaMemStoresOp(d39a7e3dd461408784e0221fffc31232): perf score=2.188937
I20260812 06:19:23.838713  2372 maintenance_manager.cc:643] P 8824592e240b4a13a253cd594bec77a9: FlushDeltaMemStoresOp(d39a7e3dd461408784e0221fffc31232) complete. Timing: real 0.015s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5687,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:23.839396  2439 maintenance_manager.cc:419] P 8824592e240b4a13a253cd594bec77a9: Scheduling MajorDeltaCompactionOp(d39a7e3dd461408784e0221fffc31232): perf score=1.000000
I20260812 06:19:23.974010  2372 maintenance_manager.cc:643] P 8824592e240b4a13a253cd594bec77a9: MajorDeltaCompactionOp(d39a7e3dd461408784e0221fffc31232) complete. Timing: real 0.134s	user 0.095s	sys 0.036s 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":413,"lbm_read_time_us":8521,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25530,"lbm_writes_lt_1ms":443,"mutex_wait_us":57,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":2000}
I20260812 06:19:23.974610  2439 maintenance_manager.cc:419] P 8824592e240b4a13a253cd594bec77a9: Scheduling FlushDeltaMemStoresOp(d39a7e3dd461408784e0221fffc31232): perf score=7.149875
I20260812 06:19:24.002846  2372 maintenance_manager.cc:643] P 8824592e240b4a13a253cd594bec77a9: FlushDeltaMemStoresOp(d39a7e3dd461408784e0221fffc31232) complete. Timing: real 0.027s	user 0.016s	sys 0.008s Metrics: {"bytes_written":8615323,"delete_count":0,"lbm_write_time_us":11279,"lbm_writes_lt_1ms":213,"reinsert_count":0,"update_count":1050}
I20260812 06:19:24.003423  2439 maintenance_manager.cc:419] P 8824592e240b4a13a253cd594bec77a9: Scheduling FlushDeltaMemStoresOp(d39a7e3dd461408784e0221fffc31232): perf score=2.188937
I20260812 06:19:24.023049  2372 maintenance_manager.cc:643] P 8824592e240b4a13a253cd594bec77a9: FlushDeltaMemStoresOp(d39a7e3dd461408784e0221fffc31232) complete. Timing: real 0.019s	user 0.002s	sys 0.015s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4121,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:24.023572  2439 maintenance_manager.cc:419] P 8824592e240b4a13a253cd594bec77a9: Scheduling MajorDeltaCompactionOp(d39a7e3dd461408784e0221fffc31232): perf score=1.000000
I20260812 06:19:24.220960  2372 maintenance_manager.cc:643] P 8824592e240b4a13a253cd594bec77a9: MajorDeltaCompactionOp(d39a7e3dd461408784e0221fffc31232) complete. Timing: real 0.197s	user 0.153s	sys 0.041s Metrics: {"cfile_cache_miss":332,"cfile_cache_miss_bytes":16569856,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":492,"lbm_read_time_us":13256,"lbm_reads_lt_1ms":372,"lbm_write_time_us":26927,"lbm_writes_lt_1ms":343,"mutex_wait_us":36,"peak_mem_usage":38262756,"reinsert_count":0,"spinlock_wait_cycles":16512,"update_count":1500}
I20260812 06:19:24.222676  2439 maintenance_manager.cc:419] P 8824592e240b4a13a253cd594bec77a9: Scheduling FlushDeltaMemStoresOp(d39a7e3dd461408784e0221fffc31232): perf score=14.095187
I20260812 06:19:24.270551  2372 maintenance_manager.cc:643] P 8824592e240b4a13a253cd594bec77a9: FlushDeltaMemStoresOp(d39a7e3dd461408784e0221fffc31232) complete. Timing: real 0.047s	user 0.021s	sys 0.024s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20886,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:24.271143  2439 maintenance_manager.cc:419] P 8824592e240b4a13a253cd594bec77a9: Scheduling FlushDeltaMemStoresOp(d39a7e3dd461408784e0221fffc31232): perf score=2.188937
I20260812 06:19:24.287504  2372 maintenance_manager.cc:643] P 8824592e240b4a13a253cd594bec77a9: FlushDeltaMemStoresOp(d39a7e3dd461408784e0221fffc31232) complete. Timing: real 0.016s	user 0.011s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6294,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:24.288195  2439 maintenance_manager.cc:419] P 8824592e240b4a13a253cd594bec77a9: Scheduling MajorDeltaCompactionOp(d39a7e3dd461408784e0221fffc31232): perf score=1.000000
I20260812 06:19:24.447945  2372 maintenance_manager.cc:643] P 8824592e240b4a13a253cd594bec77a9: MajorDeltaCompactionOp(d39a7e3dd461408784e0221fffc31232) complete. Timing: real 0.160s	user 0.100s	sys 0.048s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":926,"lbm_read_time_us":8184,"lbm_reads_lt_1ms":568,"lbm_write_time_us":31909,"lbm_writes_lt_1ms":543,"mutex_wait_us":300,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":11648,"update_count":2500}
I20260812 06:19:24.448709  2439 maintenance_manager.cc:419] P 8824592e240b4a13a253cd594bec77a9: Scheduling FlushDeltaMemStoresOp(d39a7e3dd461408784e0221fffc31232): perf score=14.095187
I20260812 06:19:24.492666  2372 maintenance_manager.cc:643] P 8824592e240b4a13a253cd594bec77a9: FlushDeltaMemStoresOp(d39a7e3dd461408784e0221fffc31232) complete. Timing: real 0.044s	user 0.028s	sys 0.016s Metrics: {"bytes_written":16409899,"delete_count":0,"lbm_write_time_us":19468,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:24.493232  2439 maintenance_manager.cc:419] P 8824592e240b4a13a253cd594bec77a9: Scheduling FlushDeltaMemStoresOp(d39a7e3dd461408784e0221fffc31232): perf score=2.188937
I20260812 06:19:24.508383  2372 maintenance_manager.cc:643] P 8824592e240b4a13a253cd594bec77a9: FlushDeltaMemStoresOp(d39a7e3dd461408784e0221fffc31232) complete. Timing: real 0.015s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5623,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:24.509014  2439 maintenance_manager.cc:419] P 8824592e240b4a13a253cd594bec77a9: Scheduling FlushMRSOp(d39a7e3dd461408784e0221fffc31232): perf score=1.000000
I20260812 06:19:24.538359  2372 maintenance_manager.cc:643] P 8824592e240b4a13a253cd594bec77a9: FlushMRSOp(d39a7e3dd461408784e0221fffc31232) complete. Timing: real 0.029s	user 0.023s	sys 0.005s Metrics: {"bytes_written":1234473,"cfile_init":1,"dirs.queue_time_us":68,"dirs.run_cpu_time_us":160,"dirs.run_wall_time_us":1365,"drs_written":1,"lbm_read_time_us":55,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1905,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":30}
I20260812 06:19:24.539268  2439 maintenance_manager.cc:419] P 8824592e240b4a13a253cd594bec77a9: Scheduling LogGCOp(d39a7e3dd461408784e0221fffc31232): free 124257240 bytes of WAL
I20260812 06:19:24.539539  2372 log_reader.cc:385] T d39a7e3dd461408784e0221fffc31232: removed 12 log segments from log reader
I20260812 06:19:24.539618  2372 log.cc:1079] T d39a7e3dd461408784e0221fffc31232 P 8824592e240b4a13a253cd594bec77a9: Deleting log segment in path: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515562549282-2253-0/minicluster-data/ts-0-root/wals/d39a7e3dd461408784e0221fffc31232/wal-000000003 (ops 12-16)
I20260812 06:19:24.539677  2372 log.cc:1079] T d39a7e3dd461408784e0221fffc31232 P 8824592e240b4a13a253cd594bec77a9: Deleting log segment in path: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515562549282-2253-0/minicluster-data/ts-0-root/wals/d39a7e3dd461408784e0221fffc31232/wal-000000004 (ops 17-21)
I20260812 06:19:24.539718  2372 log.cc:1079] T d39a7e3dd461408784e0221fffc31232 P 8824592e240b4a13a253cd594bec77a9: Deleting log segment in path: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515562549282-2253-0/minicluster-data/ts-0-root/wals/d39a7e3dd461408784e0221fffc31232/wal-000000005 (ops 22-26)
I20260812 06:19:24.539755  2372 log.cc:1079] T d39a7e3dd461408784e0221fffc31232 P 8824592e240b4a13a253cd594bec77a9: Deleting log segment in path: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515562549282-2253-0/minicluster-data/ts-0-root/wals/d39a7e3dd461408784e0221fffc31232/wal-000000006 (ops 27-30)
I20260812 06:19:24.539791  2372 log.cc:1079] T d39a7e3dd461408784e0221fffc31232 P 8824592e240b4a13a253cd594bec77a9: Deleting log segment in path: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515562549282-2253-0/minicluster-data/ts-0-root/wals/d39a7e3dd461408784e0221fffc31232/wal-000000007 (ops 31-35)
I20260812 06:19:24.539829  2372 log.cc:1079] T d39a7e3dd461408784e0221fffc31232 P 8824592e240b4a13a253cd594bec77a9: Deleting log segment in path: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515562549282-2253-0/minicluster-data/ts-0-root/wals/d39a7e3dd461408784e0221fffc31232/wal-000000008 (ops 36-40)
I20260812 06:19:24.539865  2372 log.cc:1079] T d39a7e3dd461408784e0221fffc31232 P 8824592e240b4a13a253cd594bec77a9: Deleting log segment in path: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515562549282-2253-0/minicluster-data/ts-0-root/wals/d39a7e3dd461408784e0221fffc31232/wal-000000009 (ops 41-45)
I20260812 06:19:24.539902  2372 log.cc:1079] T d39a7e3dd461408784e0221fffc31232 P 8824592e240b4a13a253cd594bec77a9: Deleting log segment in path: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515562549282-2253-0/minicluster-data/ts-0-root/wals/d39a7e3dd461408784e0221fffc31232/wal-000000010 (ops 46-50)
I20260812 06:19:24.539937  2372 log.cc:1079] T d39a7e3dd461408784e0221fffc31232 P 8824592e240b4a13a253cd594bec77a9: Deleting log segment in path: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515562549282-2253-0/minicluster-data/ts-0-root/wals/d39a7e3dd461408784e0221fffc31232/wal-000000011 (ops 51-55)
I20260812 06:19:24.539973  2372 log.cc:1079] T d39a7e3dd461408784e0221fffc31232 P 8824592e240b4a13a253cd594bec77a9: Deleting log segment in path: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515562549282-2253-0/minicluster-data/ts-0-root/wals/d39a7e3dd461408784e0221fffc31232/wal-000000012 (ops 56-60)
I20260812 06:19:24.540009  2372 log.cc:1079] T d39a7e3dd461408784e0221fffc31232 P 8824592e240b4a13a253cd594bec77a9: Deleting log segment in path: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515562549282-2253-0/minicluster-data/ts-0-root/wals/d39a7e3dd461408784e0221fffc31232/wal-000000013 (ops 61-65)
I20260812 06:19:24.540046  2372 log.cc:1079] T d39a7e3dd461408784e0221fffc31232 P 8824592e240b4a13a253cd594bec77a9: Deleting log segment in path: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515562549282-2253-0/minicluster-data/ts-0-root/wals/d39a7e3dd461408784e0221fffc31232/wal-000000014 (ops 66-70)
I20260812 06:19:24.568423  2372 maintenance_manager.cc:643] P 8824592e240b4a13a253cd594bec77a9: LogGCOp(d39a7e3dd461408784e0221fffc31232) complete. Timing: real 0.029s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:19:24.568876  2439 maintenance_manager.cc:419] P 8824592e240b4a13a253cd594bec77a9: Scheduling FlushDeltaMemStoresOp(d39a7e3dd461408784e0221fffc31232): perf score=3.181125
I20260812 06:19:24.586540  2372 maintenance_manager.cc:643] P 8824592e240b4a13a253cd594bec77a9: FlushDeltaMemStoresOp(d39a7e3dd461408784e0221fffc31232) complete. Timing: real 0.017s	user 0.009s	sys 0.006s Metrics: {"bytes_written":4512900,"delete_count":0,"lbm_write_time_us":6946,"lbm_writes_lt_1ms":113,"reinsert_count":0,"update_count":550}
I20260812 06:19:24.586973  2439 maintenance_manager.cc:419] P 8824592e240b4a13a253cd594bec77a9: Scheduling FlushDeltaMemStoresOp(d39a7e3dd461408784e0221fffc31232): perf score=2.188937
I20260812 06:19:24.597012  2372 maintenance_manager.cc:643] P 8824592e240b4a13a253cd594bec77a9: FlushDeltaMemStoresOp(d39a7e3dd461408784e0221fffc31232) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":3945,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:24.597457  2439 maintenance_manager.cc:419] P 8824592e240b4a13a253cd594bec77a9: Scheduling MajorDeltaCompactionOp(d39a7e3dd461408784e0221fffc31232): perf score=1.000000
I20260812 06:19:24.784606  2372 maintenance_manager.cc:643] P 8824592e240b4a13a253cd594bec77a9: MajorDeltaCompactionOp(d39a7e3dd461408784e0221fffc31232) complete. Timing: real 0.187s	user 0.119s	sys 0.067s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979734,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":575,"lbm_read_time_us":12340,"lbm_reads_lt_1ms":774,"lbm_write_time_us":39978,"lbm_writes_lt_1ms":743,"mutex_wait_us":44,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":175104,"thread_start_us":97,"threads_started":1,"update_count":3500}
I20260812 06:19:24.785971  2439 maintenance_manager.cc:419] P 8824592e240b4a13a253cd594bec77a9: Scheduling UndoDeltaBlockGCOp(d39a7e3dd461408784e0221fffc31232): 472 bytes on disk
I20260812 06:19:24.786448  2372 maintenance_manager.cc:643] P 8824592e240b4a13a253cd594bec77a9: UndoDeltaBlockGCOp(d39a7e3dd461408784e0221fffc31232) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":46,"lbm_reads_lt_1ms":4}
I20260812 06:19:24.787112  2439 maintenance_manager.cc:419] P 8824592e240b4a13a253cd594bec77a9: Scheduling FlushDeltaMemStoresOp(d39a7e3dd461408784e0221fffc31232): perf score=14.095187
I20260812 06:19:24.842553  2372 maintenance_manager.cc:643] P 8824592e240b4a13a253cd594bec77a9: FlushDeltaMemStoresOp(d39a7e3dd461408784e0221fffc31232) complete. Timing: real 0.055s	user 0.033s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22858,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:24.843119  2439 maintenance_manager.cc:419] P 8824592e240b4a13a253cd594bec77a9: Scheduling FlushDeltaMemStoresOp(d39a7e3dd461408784e0221fffc31232): perf score=2.188937
I20260812 06:19:24.858808  2372 maintenance_manager.cc:643] P 8824592e240b4a13a253cd594bec77a9: FlushDeltaMemStoresOp(d39a7e3dd461408784e0221fffc31232) complete. Timing: real 0.015s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5778,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:24.859586  2439 maintenance_manager.cc:419] P 8824592e240b4a13a253cd594bec77a9: Scheduling MajorDeltaCompactionOp(d39a7e3dd461408784e0221fffc31232): perf score=1.000000
I20260812 06:19:25.021237  2372 maintenance_manager.cc:643] P 8824592e240b4a13a253cd594bec77a9: MajorDeltaCompactionOp(d39a7e3dd461408784e0221fffc31232) complete. Timing: real 0.161s	user 0.119s	sys 0.039s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":531,"lbm_read_time_us":9777,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31540,"lbm_writes_lt_1ms":543,"mutex_wait_us":70,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":384,"update_count":2500}
I20260812 06:19:25.022372  2439 maintenance_manager.cc:419] P 8824592e240b4a13a253cd594bec77a9: Scheduling FlushDeltaMemStoresOp(d39a7e3dd461408784e0221fffc31232): perf score=12.110812
I20260812 06:19:25.060804  2372 maintenance_manager.cc:643] P 8824592e240b4a13a253cd594bec77a9: FlushDeltaMemStoresOp(d39a7e3dd461408784e0221fffc31232) complete. Timing: real 0.038s	user 0.030s	sys 0.008s Metrics: {"bytes_written":13538208,"delete_count":0,"lbm_write_time_us":17208,"lbm_writes_lt_1ms":333,"reinsert_count":0,"update_count":1650}
I20260812 06:19:25.061831  2439 maintenance_manager.cc:419] P 8824592e240b4a13a253cd594bec77a9: Scheduling FlushDeltaMemStoresOp(d39a7e3dd461408784e0221fffc31232): perf score=1.196750
I20260812 06:19:25.074255  2372 maintenance_manager.cc:643] P 8824592e240b4a13a253cd594bec77a9: FlushDeltaMemStoresOp(d39a7e3dd461408784e0221fffc31232) complete. Timing: real 0.012s	user 0.010s	sys 0.001s Metrics: {"bytes_written":2871905,"delete_count":0,"lbm_write_time_us":4553,"lbm_writes_lt_1ms":73,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":350}
I20260812 06:19:25.074849  2439 maintenance_manager.cc:419] P 8824592e240b4a13a253cd594bec77a9: Scheduling MajorDeltaCompactionOp(d39a7e3dd461408784e0221fffc31232): perf score=1.000000
I20260812 06:19:25.228617  2372 maintenance_manager.cc:643] P 8824592e240b4a13a253cd594bec77a9: MajorDeltaCompactionOp(d39a7e3dd461408784e0221fffc31232) complete. Timing: real 0.154s	user 0.102s	sys 0.052s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672241,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":494,"lbm_read_time_us":12236,"lbm_reads_lt_1ms":468,"lbm_write_time_us":26810,"lbm_writes_lt_1ms":443,"mutex_wait_us":267,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11136,"update_count":2000}
I20260812 06:19:25.229326  2439 maintenance_manager.cc:419] P 8824592e240b4a13a253cd594bec77a9: Scheduling FlushDeltaMemStoresOp(d39a7e3dd461408784e0221fffc31232): perf score=10.126437
I20260812 06:19:25.268437  2372 maintenance_manager.cc:643] P 8824592e240b4a13a253cd594bec77a9: FlushDeltaMemStoresOp(d39a7e3dd461408784e0221fffc31232) complete. Timing: real 0.039s	user 0.019s	sys 0.012s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":14552,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:25.269083  2439 maintenance_manager.cc:419] P 8824592e240b4a13a253cd594bec77a9: Scheduling FlushDeltaMemStoresOp(d39a7e3dd461408784e0221fffc31232): perf score=2.188937
I20260812 06:19:25.287541  2372 maintenance_manager.cc:643] P 8824592e240b4a13a253cd594bec77a9: FlushDeltaMemStoresOp(d39a7e3dd461408784e0221fffc31232) complete. Timing: real 0.018s	user 0.011s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6661,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:25.288015  2439 maintenance_manager.cc:419] P 8824592e240b4a13a253cd594bec77a9: Scheduling MajorDeltaCompactionOp(d39a7e3dd461408784e0221fffc31232): perf score=1.000000
I20260812 06:19:25.417575  2372 maintenance_manager.cc:643] P 8824592e240b4a13a253cd594bec77a9: MajorDeltaCompactionOp(d39a7e3dd461408784e0221fffc31232) complete. Timing: real 0.129s	user 0.102s	sys 0.027s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":275,"lbm_read_time_us":9167,"lbm_reads_lt_1ms":468,"lbm_write_time_us":25918,"lbm_writes_lt_1ms":443,"mutex_wait_us":43,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7552,"update_count":2000}
I20260812 06:19:25.418316  2439 maintenance_manager.cc:419] P 8824592e240b4a13a253cd594bec77a9: Scheduling FlushDeltaMemStoresOp(d39a7e3dd461408784e0221fffc31232): perf score=10.126437
I20260812 06:19:25.457476  2372 maintenance_manager.cc:643] P 8824592e240b4a13a253cd594bec77a9: FlushDeltaMemStoresOp(d39a7e3dd461408784e0221fffc31232) complete. Timing: real 0.038s	user 0.029s	sys 0.009s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17031,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:25.457995  2439 maintenance_manager.cc:419] P 8824592e240b4a13a253cd594bec77a9: Scheduling FlushDeltaMemStoresOp(d39a7e3dd461408784e0221fffc31232): perf score=2.188937
I20260812 06:19:25.474207  2372 maintenance_manager.cc:643] P 8824592e240b4a13a253cd594bec77a9: FlushDeltaMemStoresOp(d39a7e3dd461408784e0221fffc31232) complete. Timing: real 0.016s	user 0.009s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5624,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:25.474810  2439 maintenance_manager.cc:419] P 8824592e240b4a13a253cd594bec77a9: Scheduling MajorDeltaCompactionOp(d39a7e3dd461408784e0221fffc31232): perf score=1.000000
I20260812 06:19:25.609503  2372 maintenance_manager.cc:643] P 8824592e240b4a13a253cd594bec77a9: MajorDeltaCompactionOp(d39a7e3dd461408784e0221fffc31232) complete. Timing: real 0.134s	user 0.105s	sys 0.029s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672277,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":737,"lbm_read_time_us":9276,"lbm_reads_lt_1ms":468,"lbm_write_time_us":24602,"lbm_writes_lt_1ms":443,"mutex_wait_us":319,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":25728,"update_count":2000}
I20260812 06:19:25.610286  2439 maintenance_manager.cc:419] P 8824592e240b4a13a253cd594bec77a9: Scheduling FlushDeltaMemStoresOp(d39a7e3dd461408784e0221fffc31232): perf score=10.126437
I20260812 06:19:25.655305  2372 maintenance_manager.cc:643] P 8824592e240b4a13a253cd594bec77a9: FlushDeltaMemStoresOp(d39a7e3dd461408784e0221fffc31232) complete. Timing: real 0.045s	user 0.024s	sys 0.012s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17170,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:25.655844  2439 maintenance_manager.cc:419] P 8824592e240b4a13a253cd594bec77a9: Scheduling FlushDeltaMemStoresOp(d39a7e3dd461408784e0221fffc31232): perf score=2.188937
I20260812 06:19:25.666821  2372 maintenance_manager.cc:643] P 8824592e240b4a13a253cd594bec77a9: FlushDeltaMemStoresOp(d39a7e3dd461408784e0221fffc31232) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3977,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:25.667855  2439 maintenance_manager.cc:419] P 8824592e240b4a13a253cd594bec77a9: Scheduling MajorDeltaCompactionOp(d39a7e3dd461408784e0221fffc31232): perf score=1.000000
I20260812 06:19:25.794216  2372 maintenance_manager.cc:643] P 8824592e240b4a13a253cd594bec77a9: MajorDeltaCompactionOp(d39a7e3dd461408784e0221fffc31232) complete. Timing: real 0.126s	user 0.094s	sys 0.032s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":190,"lbm_read_time_us":8228,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24391,"lbm_writes_lt_1ms":443,"mutex_wait_us":51,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":12032,"update_count":2000}
I20260812 06:19:25.794989  2439 maintenance_manager.cc:419] P 8824592e240b4a13a253cd594bec77a9: Scheduling FlushDeltaMemStoresOp(d39a7e3dd461408784e0221fffc31232): perf score=10.126437
I20260812 06:19:25.841524  2372 maintenance_manager.cc:643] P 8824592e240b4a13a253cd594bec77a9: FlushDeltaMemStoresOp(d39a7e3dd461408784e0221fffc31232) complete. Timing: real 0.046s	user 0.009s	sys 0.034s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":14524,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:25.842177  2439 maintenance_manager.cc:419] P 8824592e240b4a13a253cd594bec77a9: Scheduling FlushDeltaMemStoresOp(d39a7e3dd461408784e0221fffc31232): perf score=2.188937
I20260812 06:19:25.858228  2372 maintenance_manager.cc:643] P 8824592e240b4a13a253cd594bec77a9: FlushDeltaMemStoresOp(d39a7e3dd461408784e0221fffc31232) complete. Timing: real 0.016s	user 0.002s	sys 0.012s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6153,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:25.858803  2439 maintenance_manager.cc:419] P 8824592e240b4a13a253cd594bec77a9: Scheduling MajorDeltaCompactionOp(d39a7e3dd461408784e0221fffc31232): perf score=1.000000
I20260812 06:19:26.003489  2372 maintenance_manager.cc:643] P 8824592e240b4a13a253cd594bec77a9: MajorDeltaCompactionOp(d39a7e3dd461408784e0221fffc31232) complete. Timing: real 0.145s	user 0.099s	sys 0.043s 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":250,"lbm_read_time_us":10227,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24246,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":9088,"update_count":2000}
I20260812 06:19:26.004226  2439 maintenance_manager.cc:419] P 8824592e240b4a13a253cd594bec77a9: Scheduling FlushDeltaMemStoresOp(d39a7e3dd461408784e0221fffc31232): perf score=10.126437
I20260812 06:19:26.051210  2372 maintenance_manager.cc:643] P 8824592e240b4a13a253cd594bec77a9: FlushDeltaMemStoresOp(d39a7e3dd461408784e0221fffc31232) complete. Timing: real 0.047s	user 0.027s	sys 0.007s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":16059,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:26.051702  2439 maintenance_manager.cc:419] P 8824592e240b4a13a253cd594bec77a9: Scheduling FlushDeltaMemStoresOp(d39a7e3dd461408784e0221fffc31232): perf score=2.188937
I20260812 06:19:26.062584  2372 maintenance_manager.cc:643] P 8824592e240b4a13a253cd594bec77a9: FlushDeltaMemStoresOp(d39a7e3dd461408784e0221fffc31232) complete. Timing: real 0.011s	user 0.002s	sys 0.007s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4176,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:26.063391  2439 maintenance_manager.cc:419] P 8824592e240b4a13a253cd594bec77a9: Scheduling FlushMRSOp(d39a7e3dd461408784e0221fffc31232): perf score=1.000000
I20260812 06:19:26.094206  2372 maintenance_manager.cc:643] P 8824592e240b4a13a253cd594bec77a9: FlushMRSOp(d39a7e3dd461408784e0221fffc31232) complete. Timing: real 0.031s	user 0.029s	sys 0.000s Metrics: {"bytes_written":1275449,"cfile_init":1,"dirs.queue_time_us":65,"dirs.run_cpu_time_us":242,"dirs.run_wall_time_us":1645,"drs_written":1,"lbm_read_time_us":37,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1649,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:26.095021  2439 maintenance_manager.cc:419] P 8824592e240b4a13a253cd594bec77a9: Scheduling LogGCOp(d39a7e3dd461408784e0221fffc31232): free 129320476 bytes of WAL
I20260812 06:19:26.095278  2372 log_reader.cc:385] T d39a7e3dd461408784e0221fffc31232: removed 13 log segments from log reader
I20260812 06:19:26.095352  2372 log.cc:1079] T d39a7e3dd461408784e0221fffc31232 P 8824592e240b4a13a253cd594bec77a9: Deleting log segment in path: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515562549282-2253-0/minicluster-data/ts-0-root/wals/d39a7e3dd461408784e0221fffc31232/wal-000000015 (ops 71-75)
I20260812 06:19:26.095408  2372 log.cc:1079] T d39a7e3dd461408784e0221fffc31232 P 8824592e240b4a13a253cd594bec77a9: Deleting log segment in path: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515562549282-2253-0/minicluster-data/ts-0-root/wals/d39a7e3dd461408784e0221fffc31232/wal-000000016 (ops 76-80)
I20260812 06:19:26.095467  2372 log.cc:1079] T d39a7e3dd461408784e0221fffc31232 P 8824592e240b4a13a253cd594bec77a9: Deleting log segment in path: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515562549282-2253-0/minicluster-data/ts-0-root/wals/d39a7e3dd461408784e0221fffc31232/wal-000000017 (ops 81-84)
I20260812 06:19:26.095510  2372 log.cc:1079] T d39a7e3dd461408784e0221fffc31232 P 8824592e240b4a13a253cd594bec77a9: Deleting log segment in path: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515562549282-2253-0/minicluster-data/ts-0-root/wals/d39a7e3dd461408784e0221fffc31232/wal-000000018 (ops 85-89)
I20260812 06:19:26.095546  2372 log.cc:1079] T d39a7e3dd461408784e0221fffc31232 P 8824592e240b4a13a253cd594bec77a9: Deleting log segment in path: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515562549282-2253-0/minicluster-data/ts-0-root/wals/d39a7e3dd461408784e0221fffc31232/wal-000000019 (ops 90-94)
I20260812 06:19:26.095595  2372 log.cc:1079] T d39a7e3dd461408784e0221fffc31232 P 8824592e240b4a13a253cd594bec77a9: Deleting log segment in path: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515562549282-2253-0/minicluster-data/ts-0-root/wals/d39a7e3dd461408784e0221fffc31232/wal-000000020 (ops 95-98)
I20260812 06:19:26.095633  2372 log.cc:1079] T d39a7e3dd461408784e0221fffc31232 P 8824592e240b4a13a253cd594bec77a9: Deleting log segment in path: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515562549282-2253-0/minicluster-data/ts-0-root/wals/d39a7e3dd461408784e0221fffc31232/wal-000000021 (ops 99-103)
I20260812 06:19:26.095674  2372 log.cc:1079] T d39a7e3dd461408784e0221fffc31232 P 8824592e240b4a13a253cd594bec77a9: Deleting log segment in path: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515562549282-2253-0/minicluster-data/ts-0-root/wals/d39a7e3dd461408784e0221fffc31232/wal-000000022 (ops 104-108)
I20260812 06:19:26.095712  2372 log.cc:1079] T d39a7e3dd461408784e0221fffc31232 P 8824592e240b4a13a253cd594bec77a9: Deleting log segment in path: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515562549282-2253-0/minicluster-data/ts-0-root/wals/d39a7e3dd461408784e0221fffc31232/wal-000000023 (ops 109-113)
I20260812 06:19:26.095752  2372 log.cc:1079] T d39a7e3dd461408784e0221fffc31232 P 8824592e240b4a13a253cd594bec77a9: Deleting log segment in path: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515562549282-2253-0/minicluster-data/ts-0-root/wals/d39a7e3dd461408784e0221fffc31232/wal-000000024 (ops 114-118)
I20260812 06:19:26.095793  2372 log.cc:1079] T d39a7e3dd461408784e0221fffc31232 P 8824592e240b4a13a253cd594bec77a9: Deleting log segment in path: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515562549282-2253-0/minicluster-data/ts-0-root/wals/d39a7e3dd461408784e0221fffc31232/wal-000000025 (ops 119-123)
I20260812 06:19:26.095832  2372 log.cc:1079] T d39a7e3dd461408784e0221fffc31232 P 8824592e240b4a13a253cd594bec77a9: Deleting log segment in path: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515562549282-2253-0/minicluster-data/ts-0-root/wals/d39a7e3dd461408784e0221fffc31232/wal-000000026 (ops 124-128)
I20260812 06:19:26.095871  2372 log.cc:1079] T d39a7e3dd461408784e0221fffc31232 P 8824592e240b4a13a253cd594bec77a9: Deleting log segment in path: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515562549282-2253-0/minicluster-data/ts-0-root/wals/d39a7e3dd461408784e0221fffc31232/wal-000000027 (ops 129-133)
I20260812 06:19:26.121469  2372 maintenance_manager.cc:643] P 8824592e240b4a13a253cd594bec77a9: LogGCOp(d39a7e3dd461408784e0221fffc31232) complete. Timing: real 0.026s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:19:26.122001  2439 maintenance_manager.cc:419] P 8824592e240b4a13a253cd594bec77a9: Scheduling UndoDeltaBlockGCOp(d39a7e3dd461408784e0221fffc31232): 483 bytes on disk
I20260812 06:19:26.122589  2372 maintenance_manager.cc:643] P 8824592e240b4a13a253cd594bec77a9: UndoDeltaBlockGCOp(d39a7e3dd461408784e0221fffc31232) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":50,"lbm_reads_lt_1ms":4}
I20260812 06:19:26.123384  2439 maintenance_manager.cc:419] P 8824592e240b4a13a253cd594bec77a9: Scheduling FlushDeltaMemStoresOp(d39a7e3dd461408784e0221fffc31232): perf score=4.173312
I20260812 06:19:26.146466  2372 maintenance_manager.cc:643] P 8824592e240b4a13a253cd594bec77a9: FlushDeltaMemStoresOp(d39a7e3dd461408784e0221fffc31232) complete. Timing: real 0.023s	user 0.008s	sys 0.012s Metrics: {"bytes_written":5661584,"delete_count":0,"lbm_write_time_us":6115,"lbm_writes_lt_1ms":141,"reinsert_count":0,"update_count":690}
I20260812 06:19:26.147081  2439 maintenance_manager.cc:419] P 8824592e240b4a13a253cd594bec77a9: Scheduling FlushDeltaMemStoresOp(d39a7e3dd461408784e0221fffc31232): perf score=1.196750
I20260812 06:19:26.159957  2372 maintenance_manager.cc:643] P 8824592e240b4a13a253cd594bec77a9: FlushDeltaMemStoresOp(d39a7e3dd461408784e0221fffc31232) complete. Timing: real 0.013s	user 0.003s	sys 0.007s Metrics: {"bytes_written":2543704,"delete_count":0,"lbm_write_time_us":4346,"lbm_writes_lt_1ms":65,"reinsert_count":0,"update_count":310}
I20260812 06:19:26.160585  2439 maintenance_manager.cc:419] P 8824592e240b4a13a253cd594bec77a9: Scheduling MajorDeltaCompactionOp(d39a7e3dd461408784e0221fffc31232): perf score=1.000000
I20260812 06:19:26.370786  2372 maintenance_manager.cc:643] P 8824592e240b4a13a253cd594bec77a9: MajorDeltaCompactionOp(d39a7e3dd461408784e0221fffc31232) complete. Timing: real 0.210s	user 0.137s	sys 0.065s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877303,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":707,"lbm_read_time_us":14052,"lbm_reads_lt_1ms":674,"lbm_write_time_us":36262,"lbm_writes_lt_1ms":643,"mutex_wait_us":82,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":12800,"thread_start_us":76,"threads_started":1,"update_count":3000}
I20260812 06:19:26.371829  2439 maintenance_manager.cc:419] P 8824592e240b4a13a253cd594bec77a9: Scheduling FlushDeltaMemStoresOp(d39a7e3dd461408784e0221fffc31232): perf score=14.095187
I20260812 06:19:26.438186  2372 maintenance_manager.cc:643] P 8824592e240b4a13a253cd594bec77a9: FlushDeltaMemStoresOp(d39a7e3dd461408784e0221fffc31232) complete. Timing: real 0.066s	user 0.038s	sys 0.027s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":25668,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":402,"reinsert_count":0,"update_count":2000}
I20260812 06:19:26.438812  2439 maintenance_manager.cc:419] P 8824592e240b4a13a253cd594bec77a9: Scheduling FlushDeltaMemStoresOp(d39a7e3dd461408784e0221fffc31232): perf score=2.188937
I20260812 06:19:26.449963  2372 maintenance_manager.cc:643] P 8824592e240b4a13a253cd594bec77a9: FlushDeltaMemStoresOp(d39a7e3dd461408784e0221fffc31232) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4339,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:26.450446  2439 maintenance_manager.cc:419] P 8824592e240b4a13a253cd594bec77a9: Scheduling MajorDeltaCompactionOp(d39a7e3dd461408784e0221fffc31232): perf score=1.000000
I20260812 06:19:26.631014  2372 maintenance_manager.cc:643] P 8824592e240b4a13a253cd594bec77a9: MajorDeltaCompactionOp(d39a7e3dd461408784e0221fffc31232) complete. Timing: real 0.180s	user 0.119s	sys 0.049s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774689,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":435,"lbm_read_time_us":12251,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29355,"lbm_writes_lt_1ms":543,"mutex_wait_us":99,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2500}
I20260812 06:19:26.631527  2439 maintenance_manager.cc:419] P 8824592e240b4a13a253cd594bec77a9: Scheduling FlushDeltaMemStoresOp(d39a7e3dd461408784e0221fffc31232): perf score=14.095187
I20260812 06:19:26.689424  2372 maintenance_manager.cc:643] P 8824592e240b4a13a253cd594bec77a9: FlushDeltaMemStoresOp(d39a7e3dd461408784e0221fffc31232) complete. Timing: real 0.057s	user 0.037s	sys 0.012s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":22839,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:26.689899  2439 maintenance_manager.cc:419] P 8824592e240b4a13a253cd594bec77a9: Scheduling FlushDeltaMemStoresOp(d39a7e3dd461408784e0221fffc31232): perf score=2.188937
I20260812 06:19:26.701305  2372 maintenance_manager.cc:643] P 8824592e240b4a13a253cd594bec77a9: FlushDeltaMemStoresOp(d39a7e3dd461408784e0221fffc31232) complete. Timing: real 0.011s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4105,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:26.701926  2439 maintenance_manager.cc:419] P 8824592e240b4a13a253cd594bec77a9: Scheduling MajorDeltaCompactionOp(d39a7e3dd461408784e0221fffc31232): perf score=1.000000
I20260812 06:19:26.885695  2372 maintenance_manager.cc:643] P 8824592e240b4a13a253cd594bec77a9: MajorDeltaCompactionOp(d39a7e3dd461408784e0221fffc31232) complete. Timing: real 0.184s	user 0.101s	sys 0.069s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":385,"lbm_read_time_us":11692,"lbm_reads_lt_1ms":572,"lbm_write_time_us":28900,"lbm_writes_lt_1ms":543,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1792,"update_count":2500}
I20260812 06:19:26.886370  2439 maintenance_manager.cc:419] P 8824592e240b4a13a253cd594bec77a9: Scheduling FlushDeltaMemStoresOp(d39a7e3dd461408784e0221fffc31232): perf score=14.095187
I20260812 06:19:26.939124  2372 maintenance_manager.cc:643] P 8824592e240b4a13a253cd594bec77a9: FlushDeltaMemStoresOp(d39a7e3dd461408784e0221fffc31232) complete. Timing: real 0.053s	user 0.035s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22041,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:26.939635  2439 maintenance_manager.cc:419] P 8824592e240b4a13a253cd594bec77a9: Scheduling FlushDeltaMemStoresOp(d39a7e3dd461408784e0221fffc31232): perf score=2.188937
I20260812 06:19:26.951597  2372 maintenance_manager.cc:643] P 8824592e240b4a13a253cd594bec77a9: FlushDeltaMemStoresOp(d39a7e3dd461408784e0221fffc31232) complete. Timing: real 0.012s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4297,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:26.952263  2439 maintenance_manager.cc:419] P 8824592e240b4a13a253cd594bec77a9: Scheduling MajorDeltaCompactionOp(d39a7e3dd461408784e0221fffc31232): perf score=1.000000
I20260812 06:19:27.113545  2372 maintenance_manager.cc:643] P 8824592e240b4a13a253cd594bec77a9: MajorDeltaCompactionOp(d39a7e3dd461408784e0221fffc31232) complete. Timing: real 0.161s	user 0.114s	sys 0.036s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":329,"lbm_read_time_us":10082,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31812,"lbm_writes_lt_1ms":543,"mutex_wait_us":75,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":2688,"update_count":2500}
I20260812 06:19:27.114300  2439 maintenance_manager.cc:419] P 8824592e240b4a13a253cd594bec77a9: Scheduling FlushDeltaMemStoresOp(d39a7e3dd461408784e0221fffc31232): perf score=14.095187
I20260812 06:19:27.164316  2372 maintenance_manager.cc:643] P 8824592e240b4a13a253cd594bec77a9: FlushDeltaMemStoresOp(d39a7e3dd461408784e0221fffc31232) complete. Timing: real 0.050s	user 0.026s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":18528,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:27.164959  2439 maintenance_manager.cc:419] P 8824592e240b4a13a253cd594bec77a9: Scheduling FlushDeltaMemStoresOp(d39a7e3dd461408784e0221fffc31232): perf score=2.188937
I20260812 06:19:27.180442  2372 maintenance_manager.cc:643] P 8824592e240b4a13a253cd594bec77a9: FlushDeltaMemStoresOp(d39a7e3dd461408784e0221fffc31232) complete. Timing: real 0.015s	user 0.012s	sys 0.000s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":5839,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:27.181102  2439 maintenance_manager.cc:419] P 8824592e240b4a13a253cd594bec77a9: Scheduling MajorDeltaCompactionOp(d39a7e3dd461408784e0221fffc31232): perf score=1.000000
I20260812 06:19:27.339581  2372 maintenance_manager.cc:643] P 8824592e240b4a13a253cd594bec77a9: MajorDeltaCompactionOp(d39a7e3dd461408784e0221fffc31232) complete. Timing: real 0.158s	user 0.099s	sys 0.052s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774687,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":226,"lbm_read_time_us":10239,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31168,"lbm_writes_lt_1ms":543,"mutex_wait_us":58,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":15744,"update_count":2500}
I20260812 06:19:27.340308  2439 maintenance_manager.cc:419] P 8824592e240b4a13a253cd594bec77a9: Scheduling FlushDeltaMemStoresOp(d39a7e3dd461408784e0221fffc31232): perf score=14.095187
I20260812 06:19:27.388819  2372 maintenance_manager.cc:643] P 8824592e240b4a13a253cd594bec77a9: FlushDeltaMemStoresOp(d39a7e3dd461408784e0221fffc31232) complete. Timing: real 0.048s	user 0.026s	sys 0.015s Metrics: {"bytes_written":16409905,"delete_count":0,"lbm_write_time_us":18448,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:27.389381  2439 maintenance_manager.cc:419] P 8824592e240b4a13a253cd594bec77a9: Scheduling FlushDeltaMemStoresOp(d39a7e3dd461408784e0221fffc31232): perf score=2.188937
I20260812 06:19:27.401288  2372 maintenance_manager.cc:643] P 8824592e240b4a13a253cd594bec77a9: FlushDeltaMemStoresOp(d39a7e3dd461408784e0221fffc31232) complete. Timing: real 0.012s	user 0.010s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4303,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:27.402089  2439 maintenance_manager.cc:419] P 8824592e240b4a13a253cd594bec77a9: Scheduling MajorDeltaCompactionOp(d39a7e3dd461408784e0221fffc31232): perf score=1.000000
I20260812 06:19:27.554611  2372 maintenance_manager.cc:643] P 8824592e240b4a13a253cd594bec77a9: MajorDeltaCompactionOp(d39a7e3dd461408784e0221fffc31232) complete. Timing: real 0.152s	user 0.114s	sys 0.036s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774692,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":310,"lbm_read_time_us":8926,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30539,"lbm_writes_lt_1ms":543,"mutex_wait_us":32,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":1280,"update_count":2500}
I20260812 06:19:27.558521  2439 maintenance_manager.cc:419] P 8824592e240b4a13a253cd594bec77a9: Scheduling FlushDeltaMemStoresOp(d39a7e3dd461408784e0221fffc31232): perf score=11.118625
I20260812 06:19:27.599402  2372 maintenance_manager.cc:643] P 8824592e240b4a13a253cd594bec77a9: FlushDeltaMemStoresOp(d39a7e3dd461408784e0221fffc31232) complete. Timing: real 0.041s	user 0.027s	sys 0.011s Metrics: {"bytes_written":12717736,"delete_count":0,"lbm_write_time_us":18282,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:27.600036  2439 maintenance_manager.cc:419] P 8824592e240b4a13a253cd594bec77a9: Scheduling FlushDeltaMemStoresOp(d39a7e3dd461408784e0221fffc31232): perf score=2.188937
I20260812 06:19:27.611712  2372 maintenance_manager.cc:643] P 8824592e240b4a13a253cd594bec77a9: FlushDeltaMemStoresOp(d39a7e3dd461408784e0221fffc31232) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":4332,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:27.612376  2439 maintenance_manager.cc:419] P 8824592e240b4a13a253cd594bec77a9: Scheduling FlushMRSOp(d39a7e3dd461408784e0221fffc31232): perf score=1.000000
I20260812 06:19:27.647236  2372 maintenance_manager.cc:643] P 8824592e240b4a13a253cd594bec77a9: FlushMRSOp(d39a7e3dd461408784e0221fffc31232) complete. Timing: real 0.035s	user 0.027s	sys 0.005s Metrics: {"bytes_written":1275447,"cfile_init":1,"dirs.queue_time_us":79,"dirs.run_cpu_time_us":272,"dirs.run_wall_time_us":1658,"drs_written":1,"lbm_read_time_us":39,"lbm_reads_lt_1ms":4,"lbm_write_time_us":1633,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":31}
I20260812 06:19:27.647981  2439 maintenance_manager.cc:419] P 8824592e240b4a13a253cd594bec77a9: Scheduling LogGCOp(d39a7e3dd461408784e0221fffc31232): free 124710621 bytes of WAL
I20260812 06:19:27.648238  2372 log_reader.cc:385] T d39a7e3dd461408784e0221fffc31232: removed 12 log segments from log reader
I20260812 06:19:27.648291  2372 log.cc:1079] T d39a7e3dd461408784e0221fffc31232 P 8824592e240b4a13a253cd594bec77a9: Deleting log segment in path: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515562549282-2253-0/minicluster-data/ts-0-root/wals/d39a7e3dd461408784e0221fffc31232/wal-000000028 (ops 134-138)
I20260812 06:19:27.648321  2372 log.cc:1079] T d39a7e3dd461408784e0221fffc31232 P 8824592e240b4a13a253cd594bec77a9: Deleting log segment in path: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515562549282-2253-0/minicluster-data/ts-0-root/wals/d39a7e3dd461408784e0221fffc31232/wal-000000029 (ops 139-143)
I20260812 06:19:27.648339  2372 log.cc:1079] T d39a7e3dd461408784e0221fffc31232 P 8824592e240b4a13a253cd594bec77a9: Deleting log segment in path: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515562549282-2253-0/minicluster-data/ts-0-root/wals/d39a7e3dd461408784e0221fffc31232/wal-000000030 (ops 144-148)
I20260812 06:19:27.648404  2372 log.cc:1079] T d39a7e3dd461408784e0221fffc31232 P 8824592e240b4a13a253cd594bec77a9: Deleting log segment in path: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515562549282-2253-0/minicluster-data/ts-0-root/wals/d39a7e3dd461408784e0221fffc31232/wal-000000031 (ops 149-153)
I20260812 06:19:27.648437  2372 log.cc:1079] T d39a7e3dd461408784e0221fffc31232 P 8824592e240b4a13a253cd594bec77a9: Deleting log segment in path: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515562549282-2253-0/minicluster-data/ts-0-root/wals/d39a7e3dd461408784e0221fffc31232/wal-000000032 (ops 154-158)
I20260812 06:19:27.648519  2372 log.cc:1079] T d39a7e3dd461408784e0221fffc31232 P 8824592e240b4a13a253cd594bec77a9: Deleting log segment in path: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515562549282-2253-0/minicluster-data/ts-0-root/wals/d39a7e3dd461408784e0221fffc31232/wal-000000033 (ops 159-163)
I20260812 06:19:27.648561  2372 log.cc:1079] T d39a7e3dd461408784e0221fffc31232 P 8824592e240b4a13a253cd594bec77a9: Deleting log segment in path: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515562549282-2253-0/minicluster-data/ts-0-root/wals/d39a7e3dd461408784e0221fffc31232/wal-000000034 (ops 164-168)
I20260812 06:19:27.648604  2372 log.cc:1079] T d39a7e3dd461408784e0221fffc31232 P 8824592e240b4a13a253cd594bec77a9: Deleting log segment in path: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515562549282-2253-0/minicluster-data/ts-0-root/wals/d39a7e3dd461408784e0221fffc31232/wal-000000035 (ops 169-173)
I20260812 06:19:27.648641  2372 log.cc:1079] T d39a7e3dd461408784e0221fffc31232 P 8824592e240b4a13a253cd594bec77a9: Deleting log segment in path: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515562549282-2253-0/minicluster-data/ts-0-root/wals/d39a7e3dd461408784e0221fffc31232/wal-000000036 (ops 174-178)
I20260812 06:19:27.648706  2372 log.cc:1079] T d39a7e3dd461408784e0221fffc31232 P 8824592e240b4a13a253cd594bec77a9: Deleting log segment in path: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515562549282-2253-0/minicluster-data/ts-0-root/wals/d39a7e3dd461408784e0221fffc31232/wal-000000037 (ops 179-183)
I20260812 06:19:27.648748  2372 log.cc:1079] T d39a7e3dd461408784e0221fffc31232 P 8824592e240b4a13a253cd594bec77a9: Deleting log segment in path: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515562549282-2253-0/minicluster-data/ts-0-root/wals/d39a7e3dd461408784e0221fffc31232/wal-000000038 (ops 184-188)
I20260812 06:19:27.648788  2372 log.cc:1079] T d39a7e3dd461408784e0221fffc31232 P 8824592e240b4a13a253cd594bec77a9: Deleting log segment in path: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_0.1786515562549282-2253-0/minicluster-data/ts-0-root/wals/d39a7e3dd461408784e0221fffc31232/wal-000000039 (ops 189-193)
I20260812 06:19:27.676589  2372 maintenance_manager.cc:643] P 8824592e240b4a13a253cd594bec77a9: LogGCOp(d39a7e3dd461408784e0221fffc31232) complete. Timing: real 0.028s	user 0.000s	sys 0.028s Metrics: {}
I20260812 06:19:27.677004  2439 maintenance_manager.cc:419] P 8824592e240b4a13a253cd594bec77a9: Scheduling UndoDeltaBlockGCOp(d39a7e3dd461408784e0221fffc31232): 482 bytes on disk
I20260812 06:19:27.677419  2372 maintenance_manager.cc:643] P 8824592e240b4a13a253cd594bec77a9: UndoDeltaBlockGCOp(d39a7e3dd461408784e0221fffc31232) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":51,"lbm_reads_lt_1ms":4}
I20260812 06:19:27.677943  2439 maintenance_manager.cc:419] P 8824592e240b4a13a253cd594bec77a9: Scheduling FlushDeltaMemStoresOp(d39a7e3dd461408784e0221fffc31232): perf score=6.157687
I20260812 06:19:27.704521  2372 maintenance_manager.cc:643] P 8824592e240b4a13a253cd594bec77a9: FlushDeltaMemStoresOp(d39a7e3dd461408784e0221fffc31232) complete. Timing: real 0.026s	user 0.014s	sys 0.009s Metrics: {"bytes_written":8205078,"delete_count":0,"lbm_write_time_us":10536,"lbm_writes_lt_1ms":203,"reinsert_count":0,"update_count":1000}
I20260812 06:19:27.705106  2439 maintenance_manager.cc:419] P 8824592e240b4a13a253cd594bec77a9: Scheduling MajorDeltaCompactionOp(d39a7e3dd461408784e0221fffc31232): perf score=1.000000
I20260812 06:19:27.764927  2253 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.897s	user 1.816s	sys 0.153s
I20260812 06:19:27.852715  2253 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.087s	user 0.003s	sys 0.000s
I20260812 06:19:27.853389  2253 tablet_server.cc:179] TabletServer@127.2.51.65:0 shutting down...
I20260812 06:19:27.865746  2372 maintenance_manager.cc:643] P 8824592e240b4a13a253cd594bec77a9: MajorDeltaCompactionOp(d39a7e3dd461408784e0221fffc31232) complete. Timing: real 0.160s	user 0.116s	sys 0.044s Metrics: {"cfile_cache_miss":633,"cfile_cache_miss_bytes":28877213,"cfile_init":7,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":332,"lbm_read_time_us":12196,"lbm_reads_lt_1ms":661,"lbm_write_time_us":31024,"lbm_writes_lt_1ms":643,"mutex_wait_us":23,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":23040,"thread_start_us":98,"threads_started":1,"update_count":3000}
I20260812 06:19:27.867998  2253 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:27.868431  2253 tablet_replica.cc:333] T d39a7e3dd461408784e0221fffc31232 P 8824592e240b4a13a253cd594bec77a9: stopping tablet replica
I20260812 06:19:27.868723  2253 raft_consensus.cc:2243] T d39a7e3dd461408784e0221fffc31232 P 8824592e240b4a13a253cd594bec77a9 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:27.868985  2253 raft_consensus.cc:2272] T d39a7e3dd461408784e0221fffc31232 P 8824592e240b4a13a253cd594bec77a9 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:27.876433  2253 tablet_server.cc:196] TabletServer@127.2.51.65:0 shutdown complete.
I20260812 06:19:27.922079  2253 master.cc:562] Master@127.2.51.126:42649 shutting down...
I20260812 06:19:27.925838  2253 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 3d93989b20fc43189d5214036de907f8 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:27.926003  2253 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 3d93989b20fc43189d5214036de907f8 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:27.926059  2253 tablet_replica.cc:333] T 00000000000000000000000000000000 P 3d93989b20fc43189d5214036de907f8: stopping tablet replica
I20260812 06:19:27.938527  2253 master.cc:584] Master@127.2.51.126:42649 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/0 (5464 ms)
[ RUN      ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1
I20260812 06:19:28.024596  2253 internal_mini_cluster.cc:156] Creating distributed mini masters. Addrs: 127.2.51.126:35711
I20260812 06:19:28.025002  2253 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:28.027222  2473 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:28.027284  2474 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:28.027340  2253 server_base.cc:1061] running on GCE node
W20260812 06:19:28.027379  2476 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:28.027643  2253 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:28.027697  2253 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:28.027714  2253 hybrid_clock.cc:648] HybridClock initialized: now 1786515568027714 us; error 0 us; skew 500 ppm
I20260812 06:19:28.028700  2253 webserver.cc:533] Webserver started at http://127.2.51.126:42359/ using document root <none> and password file <none>
I20260812 06:19:28.028883  2253 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:28.028939  2253 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:28.029042  2253 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:28.029457  2253 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515562549282-2253-0/minicluster-data/master-0-root/instance:
uuid: "601892bd52a44d2bb8903caedeca21c8"
format_stamp: "Formatted at 2026-08-12 06:19:28 on dist-test-slave-10pc"
I20260812 06:19:28.030952  2253 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:28.031910  2482 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:28.032166  2253 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:28.032269  2253 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515562549282-2253-0/minicluster-data/master-0-root
uuid: "601892bd52a44d2bb8903caedeca21c8"
format_stamp: "Formatted at 2026-08-12 06:19:28 on dist-test-slave-10pc"
I20260812 06:19:28.032361  2253 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515562549282-2253-0/minicluster-data/master-0-root
metadata directory: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515562549282-2253-0/minicluster-data/master-0-root
1 data directories: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515562549282-2253-0/minicluster-data/master-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:28.045918  2253 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:28.046386  2253 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:28.050963  2253 rpc_server.cc:307] RPC server started. Bound to: 127.2.51.126:35711
I20260812 06:19:28.056427  2546 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.2.51.126:35711 every 8 connection(s)
I20260812 06:19:28.069305  2547 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 00000000000000000000000000000000. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:28.071460  2547 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 601892bd52a44d2bb8903caedeca21c8: Bootstrap starting.
I20260812 06:19:28.072319  2547 tablet_bootstrap.cc:654] T 00000000000000000000000000000000 P 601892bd52a44d2bb8903caedeca21c8: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:28.073452  2547 tablet_bootstrap.cc:492] T 00000000000000000000000000000000 P 601892bd52a44d2bb8903caedeca21c8: No bootstrap required, opened a new log
I20260812 06:19:28.073851  2547 raft_consensus.cc:359] T 00000000000000000000000000000000 P 601892bd52a44d2bb8903caedeca21c8 [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "601892bd52a44d2bb8903caedeca21c8" member_type: VOTER }
I20260812 06:19:28.074016  2547 raft_consensus.cc:385] T 00000000000000000000000000000000 P 601892bd52a44d2bb8903caedeca21c8 [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:28.074092  2547 raft_consensus.cc:740] T 00000000000000000000000000000000 P 601892bd52a44d2bb8903caedeca21c8 [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: 601892bd52a44d2bb8903caedeca21c8, State: Initialized, Role: FOLLOWER
I20260812 06:19:28.074266  2547 consensus_queue.cc:260] T 00000000000000000000000000000000 P 601892bd52a44d2bb8903caedeca21c8 [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: "601892bd52a44d2bb8903caedeca21c8" member_type: VOTER }
I20260812 06:19:28.074362  2547 raft_consensus.cc:399] T 00000000000000000000000000000000 P 601892bd52a44d2bb8903caedeca21c8 [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:28.074411  2547 raft_consensus.cc:493] T 00000000000000000000000000000000 P 601892bd52a44d2bb8903caedeca21c8 [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:28.074469  2547 raft_consensus.cc:3060] T 00000000000000000000000000000000 P 601892bd52a44d2bb8903caedeca21c8 [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:28.075142  2547 raft_consensus.cc:515] T 00000000000000000000000000000000 P 601892bd52a44d2bb8903caedeca21c8 [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "601892bd52a44d2bb8903caedeca21c8" member_type: VOTER }
I20260812 06:19:28.075294  2547 leader_election.cc:304] T 00000000000000000000000000000000 P 601892bd52a44d2bb8903caedeca21c8 [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: 601892bd52a44d2bb8903caedeca21c8; no voters: 
I20260812 06:19:28.075510  2547 leader_election.cc:290] T 00000000000000000000000000000000 P 601892bd52a44d2bb8903caedeca21c8 [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:28.075659  2551 raft_consensus.cc:2804] T 00000000000000000000000000000000 P 601892bd52a44d2bb8903caedeca21c8 [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:28.075941  2551 raft_consensus.cc:697] T 00000000000000000000000000000000 P 601892bd52a44d2bb8903caedeca21c8 [term 1 LEADER]: Becoming Leader. State: Replica: 601892bd52a44d2bb8903caedeca21c8, State: Running, Role: LEADER
I20260812 06:19:28.076031  2547 sys_catalog.cc:565] T 00000000000000000000000000000000 P 601892bd52a44d2bb8903caedeca21c8 [sys.catalog]: configured and running, proceeding with master startup.
I20260812 06:19:28.076084  2551 consensus_queue.cc:237] T 00000000000000000000000000000000 P 601892bd52a44d2bb8903caedeca21c8 [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: "601892bd52a44d2bb8903caedeca21c8" member_type: VOTER }
I20260812 06:19:28.076550  2552 sys_catalog.cc:455] T 00000000000000000000000000000000 P 601892bd52a44d2bb8903caedeca21c8 [sys.catalog]: SysCatalogTable state changed. Reason: RaftConsensus started. Latest consensus state: current_term: 1 leader_uuid: "601892bd52a44d2bb8903caedeca21c8" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "601892bd52a44d2bb8903caedeca21c8" member_type: VOTER } }
I20260812 06:19:28.076587  2553 sys_catalog.cc:455] T 00000000000000000000000000000000 P 601892bd52a44d2bb8903caedeca21c8 [sys.catalog]: SysCatalogTable state changed. Reason: New leader 601892bd52a44d2bb8903caedeca21c8. Latest consensus state: current_term: 1 leader_uuid: "601892bd52a44d2bb8903caedeca21c8" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "601892bd52a44d2bb8903caedeca21c8" member_type: VOTER } }
I20260812 06:19:28.076706  2552 sys_catalog.cc:458] T 00000000000000000000000000000000 P 601892bd52a44d2bb8903caedeca21c8 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:28.076781  2553 sys_catalog.cc:458] T 00000000000000000000000000000000 P 601892bd52a44d2bb8903caedeca21c8 [sys.catalog]: This master's current role is: LEADER
I20260812 06:19:28.077400  2557 catalog_manager.cc:1511] Loading table and tablet metadata into memory...
I20260812 06:19:28.078106  2557 catalog_manager.cc:1520] Initializing Kudu cluster ID...
I20260812 06:19:28.078311  2253 internal_mini_cluster.cc:184] Waiting to initialize catalog manager on master 0
I20260812 06:19:28.079910  2557 catalog_manager.cc:1383] Generated new cluster ID: d6caf43d434b48a89b79f29f54ade676
I20260812 06:19:28.079972  2557 catalog_manager.cc:1531] Initializing Kudu internal certificate authority...
I20260812 06:19:28.097259  2557 catalog_manager.cc:1406] Generated new certificate authority record
I20260812 06:19:28.097784  2557 catalog_manager.cc:1540] Loading token signing keys...
I20260812 06:19:28.107633  2557 catalog_manager.cc:6092] T 00000000000000000000000000000000 P 601892bd52a44d2bb8903caedeca21c8: Generated new TSK 0
I20260812 06:19:28.107810  2557 catalog_manager.cc:1550] Initializing in-progress tserver states...
I20260812 06:19:28.110668  2253 file_cache.cc:504] Constructed file cache file cache with capacity 419430
W20260812 06:19:28.112649  2573 instance_detector.cc:116] could not retrieve OpenStack instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
W20260812 06:19:28.112774  2569 instance_detector.cc:116] could not retrieve AWS instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:28.112809  2253 server_base.cc:1061] running on GCE node
W20260812 06:19:28.112776  2570 instance_detector.cc:116] could not retrieve Azure instance metadata: Network error: curl error: HTTP response code said error: The requested URL returned error: 404
I20260812 06:19:28.113102  2253 hybrid_clock.cc:584] initializing the hybrid clock with 'system_unsync' time source
W20260812 06:19:28.113143  2253 system_unsync_time.cc:38] NTP support is disabled. Clock error bounds will not be accurate. This configuration is not suitable for distributed clusters.
I20260812 06:19:28.113166  2253 hybrid_clock.cc:648] HybridClock initialized: now 1786515568113166 us; error 0 us; skew 500 ppm
I20260812 06:19:28.114051  2253 webserver.cc:533] Webserver started at http://127.2.51.65:45517/ using document root <none> and password file <none>
I20260812 06:19:28.114244  2253 fs_manager.cc:362] Metadata directory not provided
I20260812 06:19:28.114316  2253 fs_manager.cc:368] Using write-ahead log directory (fs_wal_dir) as metadata directory
I20260812 06:19:28.114394  2253 server_base.cc:909] This appears to be a new deployment of Kudu; creating new FS layout
I20260812 06:19:28.114777  2253 fs_manager.cc:1068] Generated new instance metadata in path /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515562549282-2253-0/minicluster-data/ts-0-root/instance:
uuid: "c2c876c0cbbb49a3982f118eaa59deae"
format_stamp: "Formatted at 2026-08-12 06:19:28 on dist-test-slave-10pc"
I20260812 06:19:28.116209  2253 fs_manager.cc:696] Time spent creating directory manager: real 0.001s	user 0.002s	sys 0.000s
I20260812 06:19:28.117203  2580 log_block_manager.cc:4127] Time spent loading block containers with low live blocks: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:28.117478  2253 fs_manager.cc:730] Time spent opening block manager: real 0.001s	user 0.001s	sys 0.000s
I20260812 06:19:28.117544  2253 fs_manager.cc:647] Opened local filesystem: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515562549282-2253-0/minicluster-data/ts-0-root
uuid: "c2c876c0cbbb49a3982f118eaa59deae"
format_stamp: "Formatted at 2026-08-12 06:19:28 on dist-test-slave-10pc"
I20260812 06:19:28.117638  2253 fs_report.cc:389] FS layout report
--------------------
wal directory: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515562549282-2253-0/minicluster-data/ts-0-root
metadata directory: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515562549282-2253-0/minicluster-data/ts-0-root
1 data directories: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515562549282-2253-0/minicluster-data/ts-0-root/data
Total live blocks: 0
Total live bytes: 0
Total live bytes (after alignment): 0
Total number of LBM containers: 0 (0 full)
Did not check for missing blocks
Did not check for orphaned blocks
Total full LBM containers with extra space: 0 (0 repaired)
Total full LBM container extra space in bytes: 0 (0 repaired)
Total incomplete LBM containers: 0 (0 repaired)
Total LBM partial records: 0 (0 repaired)
Total corrupted LBM metadata records in RocksDB: 0 (0 repaired)
I20260812 06:19:28.128218  2253 rpc_server.cc:225] running with OpenSSL 1.1.1  11 Sep 2018
I20260812 06:19:28.128690  2253 kserver.cc:163] Server-wide thread pool size limit: 3276
I20260812 06:19:28.129024  2253 txn_system_client.cc:432] TxnSystemClient initialization is disabled...
I20260812 06:19:28.129510  2253 ts_tablet_manager.cc:585] Loaded tablet metadata (0 total tablets, 0 live tablets)
I20260812 06:19:28.129575  2253 ts_tablet_manager.cc:531] Time spent load tablet metadata: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:28.129637  2253 ts_tablet_manager.cc:616] Registered 0 tablets
I20260812 06:19:28.129673  2253 ts_tablet_manager.cc:595] Time spent register tablets: real 0.000s	user 0.000s	sys 0.000s
I20260812 06:19:28.134281  2253 rpc_server.cc:307] RPC server started. Bound to: 127.2.51.65:42015
I20260812 06:19:28.134320  2653 acceptor_pool.cc:272] collecting diagnostics on the listening RPC socket 127.2.51.65:42015 every 8 connection(s)
I20260812 06:19:28.145572  2654 heartbeater.cc:344] Connected to a master server at 127.2.51.126:35711
I20260812 06:19:28.145707  2654 heartbeater.cc:461] Registering TS with master...
I20260812 06:19:28.146010  2654 heartbeater.cc:507] Master 127.2.51.126:35711 requested a full tablet report, sending...
I20260812 06:19:28.146724  2502 ts_manager.cc:194] Registered new tserver with Master: c2c876c0cbbb49a3982f118eaa59deae (127.2.51.65:42015)
I20260812 06:19:28.147017  2253 internal_mini_cluster.cc:371] 1 TS(s) registered with all masters after 0.012282459s
I20260812 06:19:28.147540  2502 master_service.cc:502] Signed X509 certificate for tserver {username='slave'} at 127.0.0.1:40898
I20260812 06:19:28.154120  2502 catalog_manager.cc:2283] Servicing CreateTable request from {username='slave'} at 127.0.0.1:40900:
name: "heavy-update-compaction-test"
schema {
  columns {
    name: "key"
    type: INT64
    is_key: true
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_a"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_b"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_c"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_d"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
  columns {
    name: "val_e"
    type: STRING
    is_key: false
    is_nullable: false
    encoding: AUTO_ENCODING
    compression: DEFAULT_COMPRESSION
    cfile_block_size: 0
    immutable: false
  }
}
num_replicas: 1
split_rows_range_bounds {
}
partition_schema {
  range_schema {
  }
}
I20260812 06:19:28.163146  2613 tablet_service.cc:1511] Processing CreateTablet for tablet 091f1f9162e841779c52a4a288c6f5ed (DEFAULT_TABLE table=heavy-update-compaction-test [id=3881ba0dec414a219bc5119b047aa306]), partition=
I20260812 06:19:28.163442  2613 data_dirs.cc:400] Could only allocate 1 dirs of requested 3 for tablet 091f1f9162e841779c52a4a288c6f5ed. 1 dirs total, 0 dirs full, 0 dirs failed
I20260812 06:19:28.165737  2669 tablet_bootstrap.cc:492] T 091f1f9162e841779c52a4a288c6f5ed P c2c876c0cbbb49a3982f118eaa59deae: Bootstrap starting.
I20260812 06:19:28.166626  2669 tablet_bootstrap.cc:654] T 091f1f9162e841779c52a4a288c6f5ed P c2c876c0cbbb49a3982f118eaa59deae: Neither blocks nor log segments found. Creating new log.
I20260812 06:19:28.167630  2669 tablet_bootstrap.cc:492] T 091f1f9162e841779c52a4a288c6f5ed P c2c876c0cbbb49a3982f118eaa59deae: No bootstrap required, opened a new log
I20260812 06:19:28.167717  2669 ts_tablet_manager.cc:1403] T 091f1f9162e841779c52a4a288c6f5ed P c2c876c0cbbb49a3982f118eaa59deae: Time spent bootstrapping tablet: real 0.002s	user 0.001s	sys 0.000s
I20260812 06:19:28.168212  2669 raft_consensus.cc:359] T 091f1f9162e841779c52a4a288c6f5ed P c2c876c0cbbb49a3982f118eaa59deae [term 0 FOLLOWER]: Replica starting. Triggering 0 pending ops. Active config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c2c876c0cbbb49a3982f118eaa59deae" member_type: VOTER last_known_addr { host: "127.2.51.65" port: 42015 } }
I20260812 06:19:28.168323  2669 raft_consensus.cc:385] T 091f1f9162e841779c52a4a288c6f5ed P c2c876c0cbbb49a3982f118eaa59deae [term 0 FOLLOWER]: Consensus starting up: Expiring failure detector timer to make a prompt election more likely
I20260812 06:19:28.168361  2669 raft_consensus.cc:740] T 091f1f9162e841779c52a4a288c6f5ed P c2c876c0cbbb49a3982f118eaa59deae [term 0 FOLLOWER]: Becoming Follower/Learner. State: Replica: c2c876c0cbbb49a3982f118eaa59deae, State: Initialized, Role: FOLLOWER
I20260812 06:19:28.168530  2669 consensus_queue.cc:260] T 091f1f9162e841779c52a4a288c6f5ed P c2c876c0cbbb49a3982f118eaa59deae [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: "c2c876c0cbbb49a3982f118eaa59deae" member_type: VOTER last_known_addr { host: "127.2.51.65" port: 42015 } }
I20260812 06:19:28.168634  2669 raft_consensus.cc:399] T 091f1f9162e841779c52a4a288c6f5ed P c2c876c0cbbb49a3982f118eaa59deae [term 0 FOLLOWER]: Only one voter in the Raft config. Triggering election immediately
I20260812 06:19:28.168692  2669 raft_consensus.cc:493] T 091f1f9162e841779c52a4a288c6f5ed P c2c876c0cbbb49a3982f118eaa59deae [term 0 FOLLOWER]: Starting leader election (initial election of a single-replica configuration)
I20260812 06:19:28.168726  2669 raft_consensus.cc:3060] T 091f1f9162e841779c52a4a288c6f5ed P c2c876c0cbbb49a3982f118eaa59deae [term 0 FOLLOWER]: Advancing to term 1
I20260812 06:19:28.169432  2669 raft_consensus.cc:515] T 091f1f9162e841779c52a4a288c6f5ed P c2c876c0cbbb49a3982f118eaa59deae [term 1 FOLLOWER]: Starting leader election with config: opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c2c876c0cbbb49a3982f118eaa59deae" member_type: VOTER last_known_addr { host: "127.2.51.65" port: 42015 } }
I20260812 06:19:28.169548  2669 leader_election.cc:304] T 091f1f9162e841779c52a4a288c6f5ed P c2c876c0cbbb49a3982f118eaa59deae [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: c2c876c0cbbb49a3982f118eaa59deae; no voters: 
I20260812 06:19:28.169713  2669 leader_election.cc:290] T 091f1f9162e841779c52a4a288c6f5ed P c2c876c0cbbb49a3982f118eaa59deae [CANDIDATE]: Term 1 election: Requested vote from peers 
I20260812 06:19:28.169853  2671 raft_consensus.cc:2804] T 091f1f9162e841779c52a4a288c6f5ed P c2c876c0cbbb49a3982f118eaa59deae [term 1 FOLLOWER]: Leader election won for term 1
I20260812 06:19:28.170058  2654 heartbeater.cc:499] Master 127.2.51.126:35711 was elected leader, sending a full tablet report...
I20260812 06:19:28.170060  2671 raft_consensus.cc:697] T 091f1f9162e841779c52a4a288c6f5ed P c2c876c0cbbb49a3982f118eaa59deae [term 1 LEADER]: Becoming Leader. State: Replica: c2c876c0cbbb49a3982f118eaa59deae, State: Running, Role: LEADER
I20260812 06:19:28.170039  2669 ts_tablet_manager.cc:1434] T 091f1f9162e841779c52a4a288c6f5ed P c2c876c0cbbb49a3982f118eaa59deae: Time spent starting tablet: real 0.002s	user 0.000s	sys 0.003s
I20260812 06:19:28.170271  2671 consensus_queue.cc:237] T 091f1f9162e841779c52a4a288c6f5ed P c2c876c0cbbb49a3982f118eaa59deae [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: "c2c876c0cbbb49a3982f118eaa59deae" member_type: VOTER last_known_addr { host: "127.2.51.65" port: 42015 } }
I20260812 06:19:28.171564  2502 catalog_manager.cc:5719] T 091f1f9162e841779c52a4a288c6f5ed P c2c876c0cbbb49a3982f118eaa59deae reported cstate change: term changed from 0 to 1, leader changed from <none> to c2c876c0cbbb49a3982f118eaa59deae (127.2.51.65). New cstate: current_term: 1 leader_uuid: "c2c876c0cbbb49a3982f118eaa59deae" committed_config { opid_index: -1 OBSOLETE_local: true peers { permanent_uuid: "c2c876c0cbbb49a3982f118eaa59deae" member_type: VOTER last_known_addr { host: "127.2.51.65" port: 42015 } health_report { overall_health: HEALTHY } } }
I20260812 06:19:28.232745  2253 heavy-update-compaction-itest.cc:215] Time spent inserting: real 0.054s	user 0.011s	sys 0.012s
I20260812 06:19:28.385339  2655 maintenance_manager.cc:419] P c2c876c0cbbb49a3982f118eaa59deae: Scheduling FlushMRSOp(091f1f9162e841779c52a4a288c6f5ed): perf score=19.054940
I20260812 06:19:28.560247  2586 maintenance_manager.cc:643] P c2c876c0cbbb49a3982f118eaa59deae: FlushMRSOp(091f1f9162e841779c52a4a288c6f5ed) complete. Timing: real 0.175s	user 0.123s	sys 0.048s Metrics: {"bytes_written":12922847,"cfile_init":1,"delete_count":0,"dirs.queue_time_us":115,"dirs.run_cpu_time_us":297,"dirs.run_wall_time_us":921,"drs_written":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4,"lbm_write_time_us":44621,"lbm_writes_lt_1ms":772,"peak_mem_usage":0,"reinsert_count":0,"rows_written":104,"spinlock_wait_cycles":896,"update_count":1575}
I20260812 06:19:28.560940  2655 maintenance_manager.cc:419] P c2c876c0cbbb49a3982f118eaa59deae: Scheduling LogGCOp(091f1f9162e841779c52a4a288c6f5ed): free 20743880 bytes of WAL
I20260812 06:19:28.561204  2586 log_reader.cc:385] T 091f1f9162e841779c52a4a288c6f5ed: removed 2 log segments from log reader
I20260812 06:19:28.561254  2586 log.cc:1079] T 091f1f9162e841779c52a4a288c6f5ed P c2c876c0cbbb49a3982f118eaa59deae: Deleting log segment in path: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515562549282-2253-0/minicluster-data/ts-0-root/wals/091f1f9162e841779c52a4a288c6f5ed/wal-000000001 (ops 1-6)
I20260812 06:19:28.561285  2586 log.cc:1079] T 091f1f9162e841779c52a4a288c6f5ed P c2c876c0cbbb49a3982f118eaa59deae: Deleting log segment in path: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515562549282-2253-0/minicluster-data/ts-0-root/wals/091f1f9162e841779c52a4a288c6f5ed/wal-000000002 (ops 7-11)
I20260812 06:19:28.565797  2586 maintenance_manager.cc:643] P c2c876c0cbbb49a3982f118eaa59deae: LogGCOp(091f1f9162e841779c52a4a288c6f5ed) complete. Timing: real 0.005s	user 0.000s	sys 0.003s Metrics: {}
I20260812 06:19:28.566213  2655 maintenance_manager.cc:419] P c2c876c0cbbb49a3982f118eaa59deae: Scheduling FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed): perf score=2.188937
I20260812 06:19:28.583001  2586 maintenance_manager.cc:643] P c2c876c0cbbb49a3982f118eaa59deae: FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed) complete. Timing: real 0.017s	user 0.007s	sys 0.003s Metrics: {"bytes_written":3487280,"delete_count":0,"lbm_write_time_us":4621,"lbm_writes_lt_1ms":88,"reinsert_count":0,"update_count":425}
I20260812 06:19:28.583460  2655 maintenance_manager.cc:419] P c2c876c0cbbb49a3982f118eaa59deae: Scheduling FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed): perf score=2.188937
I20260812 06:19:28.598054  2586 maintenance_manager.cc:643] P c2c876c0cbbb49a3982f118eaa59deae: FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed) complete. Timing: real 0.014s	user 0.013s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5755,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:28.598551  2655 maintenance_manager.cc:419] P c2c876c0cbbb49a3982f118eaa59deae: Scheduling UndoDeltaBlockGCOp(091f1f9162e841779c52a4a288c6f5ed): 16411394 bytes on disk
I20260812 06:19:28.599131  2586 maintenance_manager.cc:643] P c2c876c0cbbb49a3982f118eaa59deae: UndoDeltaBlockGCOp(091f1f9162e841779c52a4a288c6f5ed) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":82,"lbm_reads_lt_1ms":4}
I20260812 06:19:28.599597  2655 maintenance_manager.cc:419] P c2c876c0cbbb49a3982f118eaa59deae: Scheduling MajorDeltaCompactionOp(091f1f9162e841779c52a4a288c6f5ed): perf score=1.000000
I20260812 06:19:28.764691  2586 maintenance_manager.cc:643] P c2c876c0cbbb49a3982f118eaa59deae: MajorDeltaCompactionOp(091f1f9162e841779c52a4a288c6f5ed) complete. Timing: real 0.165s	user 0.121s	sys 0.044s Metrics: {"cfile_cache_miss":533,"cfile_cache_miss_bytes":24774786,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":3,"delta_iterators_relevant":3,"dirs.queue_time_us":472,"lbm_read_time_us":14054,"lbm_reads_lt_1ms":569,"lbm_write_time_us":30767,"lbm_writes_lt_1ms":543,"mutex_wait_us":23,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":22272,"thread_start_us":375,"threads_started":5,"update_count":2500}
I20260812 06:19:28.765465  2655 maintenance_manager.cc:419] P c2c876c0cbbb49a3982f118eaa59deae: Scheduling FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed): perf score=10.126437
I20260812 06:19:28.808970  2586 maintenance_manager.cc:643] P c2c876c0cbbb49a3982f118eaa59deae: FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed) complete. Timing: real 0.043s	user 0.028s	sys 0.007s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15570,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:28.809463  2655 maintenance_manager.cc:419] P c2c876c0cbbb49a3982f118eaa59deae: Scheduling FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed): perf score=2.188937
I20260812 06:19:28.819820  2586 maintenance_manager.cc:643] P c2c876c0cbbb49a3982f118eaa59deae: FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4157,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:28.820245  2655 maintenance_manager.cc:419] P c2c876c0cbbb49a3982f118eaa59deae: Scheduling MajorDeltaCompactionOp(091f1f9162e841779c52a4a288c6f5ed): perf score=1.000000
I20260812 06:19:28.958886  2586 maintenance_manager.cc:643] P c2c876c0cbbb49a3982f118eaa59deae: MajorDeltaCompactionOp(091f1f9162e841779c52a4a288c6f5ed) complete. Timing: real 0.138s	user 0.092s	sys 0.046s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":302,"lbm_read_time_us":10971,"lbm_reads_lt_1ms":472,"lbm_write_time_us":26213,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":11520,"update_count":2000}
I20260812 06:19:28.959478  2655 maintenance_manager.cc:419] P c2c876c0cbbb49a3982f118eaa59deae: Scheduling FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed): perf score=10.126437
I20260812 06:19:29.013737  2586 maintenance_manager.cc:643] P c2c876c0cbbb49a3982f118eaa59deae: FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed) complete. Timing: real 0.054s	user 0.023s	sys 0.023s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":15945,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:29.014274  2655 maintenance_manager.cc:419] P c2c876c0cbbb49a3982f118eaa59deae: Scheduling FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed): perf score=2.188937
I20260812 06:19:29.025358  2586 maintenance_manager.cc:643] P c2c876c0cbbb49a3982f118eaa59deae: FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed) complete. Timing: real 0.011s	user 0.005s	sys 0.005s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4347,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:29.025908  2655 maintenance_manager.cc:419] P c2c876c0cbbb49a3982f118eaa59deae: Scheduling MajorDeltaCompactionOp(091f1f9162e841779c52a4a288c6f5ed): perf score=1.000000
I20260812 06:19:29.174090  2586 maintenance_manager.cc:643] P c2c876c0cbbb49a3982f118eaa59deae: MajorDeltaCompactionOp(091f1f9162e841779c52a4a288c6f5ed) complete. Timing: real 0.148s	user 0.080s	sys 0.067s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":295,"lbm_read_time_us":10796,"lbm_reads_lt_1ms":472,"lbm_write_time_us":25045,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:29.174741  2655 maintenance_manager.cc:419] P c2c876c0cbbb49a3982f118eaa59deae: Scheduling FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed): perf score=10.126437
I20260812 06:19:29.225333  2586 maintenance_manager.cc:643] P c2c876c0cbbb49a3982f118eaa59deae: FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed) complete. Timing: real 0.050s	user 0.030s	sys 0.009s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17938,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:29.225768  2655 maintenance_manager.cc:419] P c2c876c0cbbb49a3982f118eaa59deae: Scheduling FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed): perf score=2.188937
I20260812 06:19:29.236260  2586 maintenance_manager.cc:643] P c2c876c0cbbb49a3982f118eaa59deae: FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed) complete. Timing: real 0.010s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4237,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:29.236868  2655 maintenance_manager.cc:419] P c2c876c0cbbb49a3982f118eaa59deae: Scheduling MajorDeltaCompactionOp(091f1f9162e841779c52a4a288c6f5ed): perf score=1.000000
I20260812 06:19:29.363380  2586 maintenance_manager.cc:643] P c2c876c0cbbb49a3982f118eaa59deae: MajorDeltaCompactionOp(091f1f9162e841779c52a4a288c6f5ed) complete. Timing: real 0.126s	user 0.102s	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":607,"lbm_read_time_us":9310,"lbm_reads_lt_1ms":472,"lbm_write_time_us":23094,"lbm_writes_lt_1ms":443,"mutex_wait_us":263,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7936,"update_count":2000}
I20260812 06:19:29.363966  2655 maintenance_manager.cc:419] P c2c876c0cbbb49a3982f118eaa59deae: Scheduling FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed): perf score=10.126437
I20260812 06:19:29.407733  2586 maintenance_manager.cc:643] P c2c876c0cbbb49a3982f118eaa59deae: FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed) complete. Timing: real 0.044s	user 0.022s	sys 0.015s Metrics: {"bytes_written":12307490,"delete_count":0,"lbm_write_time_us":17826,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:29.408171  2655 maintenance_manager.cc:419] P c2c876c0cbbb49a3982f118eaa59deae: Scheduling FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed): perf score=2.188937
I20260812 06:19:29.418828  2586 maintenance_manager.cc:643] P c2c876c0cbbb49a3982f118eaa59deae: FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed) complete. Timing: real 0.010s	user 0.006s	sys 0.003s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4122,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:29.419684  2655 maintenance_manager.cc:419] P c2c876c0cbbb49a3982f118eaa59deae: Scheduling MajorDeltaCompactionOp(091f1f9162e841779c52a4a288c6f5ed): perf score=1.000000
I20260812 06:19:29.546669  2586 maintenance_manager.cc:643] P c2c876c0cbbb49a3982f118eaa59deae: MajorDeltaCompactionOp(091f1f9162e841779c52a4a288c6f5ed) complete. Timing: real 0.127s	user 0.100s	sys 0.024s 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":216,"lbm_read_time_us":8642,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24897,"lbm_writes_lt_1ms":443,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":24192,"update_count":2000}
I20260812 06:19:29.547209  2655 maintenance_manager.cc:419] P c2c876c0cbbb49a3982f118eaa59deae: Scheduling FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed): perf score=10.126437
I20260812 06:19:29.592085  2586 maintenance_manager.cc:643] P c2c876c0cbbb49a3982f118eaa59deae: FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed) complete. Timing: real 0.045s	user 0.026s	sys 0.007s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":16120,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:29.592687  2655 maintenance_manager.cc:419] P c2c876c0cbbb49a3982f118eaa59deae: Scheduling FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed): perf score=2.188937
I20260812 06:19:29.603394  2586 maintenance_manager.cc:643] P c2c876c0cbbb49a3982f118eaa59deae: FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed) complete. Timing: real 0.011s	user 0.009s	sys 0.000s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4153,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:29.604149  2655 maintenance_manager.cc:419] P c2c876c0cbbb49a3982f118eaa59deae: Scheduling MajorDeltaCompactionOp(091f1f9162e841779c52a4a288c6f5ed): perf score=1.000000
I20260812 06:19:29.757805  2586 maintenance_manager.cc:643] P c2c876c0cbbb49a3982f118eaa59deae: MajorDeltaCompactionOp(091f1f9162e841779c52a4a288c6f5ed) complete. Timing: real 0.153s	user 0.100s	sys 0.051s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672278,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":246,"lbm_read_time_us":10422,"lbm_reads_lt_1ms":472,"lbm_write_time_us":29023,"lbm_writes_lt_1ms":443,"mutex_wait_us":49,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":19584,"update_count":2000}
I20260812 06:19:29.758533  2655 maintenance_manager.cc:419] P c2c876c0cbbb49a3982f118eaa59deae: Scheduling FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed): perf score=11.118625
I20260812 06:19:29.805370  2586 maintenance_manager.cc:643] P c2c876c0cbbb49a3982f118eaa59deae: FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed) complete. Timing: real 0.046s	user 0.022s	sys 0.023s Metrics: {"bytes_written":12717734,"delete_count":0,"lbm_write_time_us":14744,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:29.805933  2655 maintenance_manager.cc:419] P c2c876c0cbbb49a3982f118eaa59deae: Scheduling FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed): perf score=2.188937
I20260812 06:19:29.821050  2586 maintenance_manager.cc:643] P c2c876c0cbbb49a3982f118eaa59deae: FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed) complete. Timing: real 0.015s	user 0.014s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":5556,"lbm_writes_lt_1ms":93,"reinsert_count":0,"update_count":450}
I20260812 06:19:29.821609  2655 maintenance_manager.cc:419] P c2c876c0cbbb49a3982f118eaa59deae: Scheduling FlushMRSOp(091f1f9162e841779c52a4a288c6f5ed): perf score=1.000000
I20260812 06:19:29.866366  2586 maintenance_manager.cc:643] P c2c876c0cbbb49a3982f118eaa59deae: FlushMRSOp(091f1f9162e841779c52a4a288c6f5ed) complete. Timing: real 0.045s	user 0.029s	sys 0.003s Metrics: {"bytes_written":1193503,"cfile_init":1,"dirs.queue_time_us":47,"dirs.run_cpu_time_us":188,"dirs.run_wall_time_us":1415,"drs_written":1,"lbm_read_time_us":62,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2335,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:29.867024  2655 maintenance_manager.cc:419] P c2c876c0cbbb49a3982f118eaa59deae: Scheduling LogGCOp(091f1f9162e841779c52a4a288c6f5ed): free 112239315 bytes of WAL
I20260812 06:19:29.867251  2586 log_reader.cc:385] T 091f1f9162e841779c52a4a288c6f5ed: removed 11 log segments from log reader
I20260812 06:19:29.867300  2586 log.cc:1079] T 091f1f9162e841779c52a4a288c6f5ed P c2c876c0cbbb49a3982f118eaa59deae: Deleting log segment in path: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515562549282-2253-0/minicluster-data/ts-0-root/wals/091f1f9162e841779c52a4a288c6f5ed/wal-000000003 (ops 12-16)
I20260812 06:19:29.867349  2586 log.cc:1079] T 091f1f9162e841779c52a4a288c6f5ed P c2c876c0cbbb49a3982f118eaa59deae: Deleting log segment in path: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515562549282-2253-0/minicluster-data/ts-0-root/wals/091f1f9162e841779c52a4a288c6f5ed/wal-000000004 (ops 17-21)
I20260812 06:19:29.867396  2586 log.cc:1079] T 091f1f9162e841779c52a4a288c6f5ed P c2c876c0cbbb49a3982f118eaa59deae: Deleting log segment in path: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515562549282-2253-0/minicluster-data/ts-0-root/wals/091f1f9162e841779c52a4a288c6f5ed/wal-000000005 (ops 22-26)
I20260812 06:19:29.867442  2586 log.cc:1079] T 091f1f9162e841779c52a4a288c6f5ed P c2c876c0cbbb49a3982f118eaa59deae: Deleting log segment in path: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515562549282-2253-0/minicluster-data/ts-0-root/wals/091f1f9162e841779c52a4a288c6f5ed/wal-000000006 (ops 27-31)
I20260812 06:19:29.867492  2586 log.cc:1079] T 091f1f9162e841779c52a4a288c6f5ed P c2c876c0cbbb49a3982f118eaa59deae: Deleting log segment in path: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515562549282-2253-0/minicluster-data/ts-0-root/wals/091f1f9162e841779c52a4a288c6f5ed/wal-000000007 (ops 32-36)
I20260812 06:19:29.867551  2586 log.cc:1079] T 091f1f9162e841779c52a4a288c6f5ed P c2c876c0cbbb49a3982f118eaa59deae: Deleting log segment in path: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515562549282-2253-0/minicluster-data/ts-0-root/wals/091f1f9162e841779c52a4a288c6f5ed/wal-000000008 (ops 37-40)
I20260812 06:19:29.867592  2586 log.cc:1079] T 091f1f9162e841779c52a4a288c6f5ed P c2c876c0cbbb49a3982f118eaa59deae: Deleting log segment in path: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515562549282-2253-0/minicluster-data/ts-0-root/wals/091f1f9162e841779c52a4a288c6f5ed/wal-000000009 (ops 41-45)
I20260812 06:19:29.867632  2586 log.cc:1079] T 091f1f9162e841779c52a4a288c6f5ed P c2c876c0cbbb49a3982f118eaa59deae: Deleting log segment in path: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515562549282-2253-0/minicluster-data/ts-0-root/wals/091f1f9162e841779c52a4a288c6f5ed/wal-000000010 (ops 46-50)
I20260812 06:19:29.867673  2586 log.cc:1079] T 091f1f9162e841779c52a4a288c6f5ed P c2c876c0cbbb49a3982f118eaa59deae: Deleting log segment in path: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515562549282-2253-0/minicluster-data/ts-0-root/wals/091f1f9162e841779c52a4a288c6f5ed/wal-000000011 (ops 51-55)
I20260812 06:19:29.867712  2586 log.cc:1079] T 091f1f9162e841779c52a4a288c6f5ed P c2c876c0cbbb49a3982f118eaa59deae: Deleting log segment in path: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515562549282-2253-0/minicluster-data/ts-0-root/wals/091f1f9162e841779c52a4a288c6f5ed/wal-000000012 (ops 56-60)
I20260812 06:19:29.867751  2586 log.cc:1079] T 091f1f9162e841779c52a4a288c6f5ed P c2c876c0cbbb49a3982f118eaa59deae: Deleting log segment in path: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515562549282-2253-0/minicluster-data/ts-0-root/wals/091f1f9162e841779c52a4a288c6f5ed/wal-000000013 (ops 61-65)
I20260812 06:19:29.892822  2586 maintenance_manager.cc:643] P c2c876c0cbbb49a3982f118eaa59deae: LogGCOp(091f1f9162e841779c52a4a288c6f5ed) complete. Timing: real 0.026s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:19:29.893235  2655 maintenance_manager.cc:419] P c2c876c0cbbb49a3982f118eaa59deae: Scheduling UndoDeltaBlockGCOp(091f1f9162e841779c52a4a288c6f5ed): 462 bytes on disk
I20260812 06:19:29.893661  2586 maintenance_manager.cc:643] P c2c876c0cbbb49a3982f118eaa59deae: UndoDeltaBlockGCOp(091f1f9162e841779c52a4a288c6f5ed) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":54,"lbm_reads_lt_1ms":4}
I20260812 06:19:29.894147  2655 maintenance_manager.cc:419] P c2c876c0cbbb49a3982f118eaa59deae: Scheduling FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed): perf score=2.188937
I20260812 06:19:29.911345  2586 maintenance_manager.cc:643] P c2c876c0cbbb49a3982f118eaa59deae: FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed) complete. Timing: real 0.017s	user 0.005s	sys 0.006s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4749,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:29.911784  2655 maintenance_manager.cc:419] P c2c876c0cbbb49a3982f118eaa59deae: Scheduling FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed): perf score=2.188937
I20260812 06:19:29.921964  2586 maintenance_manager.cc:643] P c2c876c0cbbb49a3982f118eaa59deae: FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed) complete. Timing: real 0.010s	user 0.004s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4016,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:29.922485  2655 maintenance_manager.cc:419] P c2c876c0cbbb49a3982f118eaa59deae: Scheduling MajorDeltaCompactionOp(091f1f9162e841779c52a4a288c6f5ed): perf score=1.000000
I20260812 06:19:30.148751  2586 maintenance_manager.cc:643] P c2c876c0cbbb49a3982f118eaa59deae: MajorDeltaCompactionOp(091f1f9162e841779c52a4a288c6f5ed) complete. Timing: real 0.226s	user 0.132s	sys 0.094s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877329,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":670,"lbm_read_time_us":15241,"lbm_reads_lt_1ms":674,"lbm_write_time_us":37703,"lbm_writes_lt_1ms":643,"mutex_wait_us":49,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":896,"thread_start_us":96,"threads_started":1,"update_count":3000}
I20260812 06:19:30.150218  2655 maintenance_manager.cc:419] P c2c876c0cbbb49a3982f118eaa59deae: Scheduling FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed): perf score=14.095187
I20260812 06:19:30.212874  2586 maintenance_manager.cc:643] P c2c876c0cbbb49a3982f118eaa59deae: FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed) complete. Timing: real 0.062s	user 0.036s	sys 0.015s Metrics: {"bytes_written":16409904,"delete_count":0,"lbm_write_time_us":23294,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:30.213382  2655 maintenance_manager.cc:419] P c2c876c0cbbb49a3982f118eaa59deae: Scheduling FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed): perf score=2.188937
I20260812 06:19:30.225066  2586 maintenance_manager.cc:643] P c2c876c0cbbb49a3982f118eaa59deae: FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed) complete. Timing: real 0.011s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4199,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:30.225718  2655 maintenance_manager.cc:419] P c2c876c0cbbb49a3982f118eaa59deae: Scheduling MajorDeltaCompactionOp(091f1f9162e841779c52a4a288c6f5ed): perf score=1.000000
I20260812 06:19:30.412328  2586 maintenance_manager.cc:643] P c2c876c0cbbb49a3982f118eaa59deae: MajorDeltaCompactionOp(091f1f9162e841779c52a4a288c6f5ed) complete. Timing: real 0.186s	user 0.114s	sys 0.068s 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":225,"lbm_read_time_us":12725,"lbm_reads_lt_1ms":572,"lbm_write_time_us":31009,"lbm_writes_lt_1ms":543,"mutex_wait_us":22,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":10368,"update_count":2500}
I20260812 06:19:30.413028  2655 maintenance_manager.cc:419] P c2c876c0cbbb49a3982f118eaa59deae: Scheduling FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed): perf score=14.095187
I20260812 06:19:30.478055  2586 maintenance_manager.cc:643] P c2c876c0cbbb49a3982f118eaa59deae: FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed) complete. Timing: real 0.065s	user 0.039s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":22435,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:30.478595  2655 maintenance_manager.cc:419] P c2c876c0cbbb49a3982f118eaa59deae: Scheduling FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed): perf score=2.188937
I20260812 06:19:30.489385  2586 maintenance_manager.cc:643] P c2c876c0cbbb49a3982f118eaa59deae: FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed) complete. Timing: real 0.011s	user 0.009s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4181,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:30.489897  2655 maintenance_manager.cc:419] P c2c876c0cbbb49a3982f118eaa59deae: Scheduling MajorDeltaCompactionOp(091f1f9162e841779c52a4a288c6f5ed): perf score=1.000000
I20260812 06:19:30.673749  2586 maintenance_manager.cc:643] P c2c876c0cbbb49a3982f118eaa59deae: MajorDeltaCompactionOp(091f1f9162e841779c52a4a288c6f5ed) complete. Timing: real 0.184s	user 0.110s	sys 0.073s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":643,"lbm_read_time_us":13857,"lbm_reads_lt_1ms":572,"lbm_write_time_us":30293,"lbm_writes_lt_1ms":543,"mutex_wait_us":21,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":20480,"update_count":2500}
I20260812 06:19:30.674571  2655 maintenance_manager.cc:419] P c2c876c0cbbb49a3982f118eaa59deae: Scheduling FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed): perf score=11.118625
I20260812 06:19:30.710072  2586 maintenance_manager.cc:643] P c2c876c0cbbb49a3982f118eaa59deae: FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed) complete. Timing: real 0.035s	user 0.018s	sys 0.015s Metrics: {"bytes_written":12717735,"delete_count":0,"lbm_write_time_us":14556,"lbm_writes_lt_1ms":313,"reinsert_count":0,"update_count":1550}
I20260812 06:19:30.710757  2655 maintenance_manager.cc:419] P c2c876c0cbbb49a3982f118eaa59deae: Scheduling FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed): perf score=2.188937
I20260812 06:19:30.728680  2586 maintenance_manager.cc:643] P c2c876c0cbbb49a3982f118eaa59deae: FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed) complete. Timing: real 0.018s	user 0.017s	sys 0.000s Metrics: {"bytes_written":3692405,"delete_count":0,"lbm_write_time_us":6596,"lbm_writes_lt_1ms":93,"reinsert_count":0,"spinlock_wait_cycles":896,"update_count":450}
I20260812 06:19:30.729135  2655 maintenance_manager.cc:419] P c2c876c0cbbb49a3982f118eaa59deae: Scheduling MajorDeltaCompactionOp(091f1f9162e841779c52a4a288c6f5ed): perf score=1.000000
I20260812 06:19:30.901789  2586 maintenance_manager.cc:643] P c2c876c0cbbb49a3982f118eaa59deae: MajorDeltaCompactionOp(091f1f9162e841779c52a4a288c6f5ed) complete. Timing: real 0.172s	user 0.093s	sys 0.067s Metrics: {"cfile_cache_miss":432,"cfile_cache_miss_bytes":20672268,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":880,"lbm_read_time_us":10869,"lbm_reads_lt_1ms":468,"lbm_write_time_us":25470,"lbm_writes_lt_1ms":443,"mutex_wait_us":338,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":4480,"update_count":2000}
I20260812 06:19:30.902426  2655 maintenance_manager.cc:419] P c2c876c0cbbb49a3982f118eaa59deae: Scheduling FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed): perf score=14.095187
I20260812 06:19:30.955220  2586 maintenance_manager.cc:643] P c2c876c0cbbb49a3982f118eaa59deae: FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed) complete. Timing: real 0.053s	user 0.029s	sys 0.016s Metrics: {"bytes_written":16409903,"delete_count":0,"lbm_write_time_us":21106,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:30.955706  2655 maintenance_manager.cc:419] P c2c876c0cbbb49a3982f118eaa59deae: Scheduling FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed): perf score=2.188937
I20260812 06:19:30.966885  2586 maintenance_manager.cc:643] P c2c876c0cbbb49a3982f118eaa59deae: FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed) complete. Timing: real 0.011s	user 0.005s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":3810,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:30.967602  2655 maintenance_manager.cc:419] P c2c876c0cbbb49a3982f118eaa59deae: Scheduling MajorDeltaCompactionOp(091f1f9162e841779c52a4a288c6f5ed): perf score=1.000000
I20260812 06:19:31.114048  2586 maintenance_manager.cc:643] P c2c876c0cbbb49a3982f118eaa59deae: MajorDeltaCompactionOp(091f1f9162e841779c52a4a288c6f5ed) complete. Timing: real 0.146s	user 0.118s	sys 0.028s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774690,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":476,"lbm_read_time_us":9474,"lbm_reads_lt_1ms":572,"lbm_write_time_us":29949,"lbm_writes_lt_1ms":543,"mutex_wait_us":271,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":14848,"update_count":2500}
I20260812 06:19:31.114797  2655 maintenance_manager.cc:419] P c2c876c0cbbb49a3982f118eaa59deae: Scheduling FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed): perf score=10.126437
I20260812 06:19:31.154002  2586 maintenance_manager.cc:643] P c2c876c0cbbb49a3982f118eaa59deae: FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed) complete. Timing: real 0.039s	user 0.022s	sys 0.016s Metrics: {"bytes_written":12307491,"delete_count":0,"lbm_write_time_us":17086,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:31.154664  2655 maintenance_manager.cc:419] P c2c876c0cbbb49a3982f118eaa59deae: Scheduling FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed): perf score=2.188937
I20260812 06:19:31.171026  2586 maintenance_manager.cc:643] P c2c876c0cbbb49a3982f118eaa59deae: FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed) complete. Timing: real 0.016s	user 0.007s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":6197,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:31.171482  2655 maintenance_manager.cc:419] P c2c876c0cbbb49a3982f118eaa59deae: Scheduling MajorDeltaCompactionOp(091f1f9162e841779c52a4a288c6f5ed): perf score=1.000000
I20260812 06:19:31.304387  2586 maintenance_manager.cc:643] P c2c876c0cbbb49a3982f118eaa59deae: MajorDeltaCompactionOp(091f1f9162e841779c52a4a288c6f5ed) complete. Timing: real 0.133s	user 0.116s	sys 0.016s 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":1340,"lbm_read_time_us":7782,"lbm_reads_lt_1ms":472,"lbm_write_time_us":24343,"lbm_writes_lt_1ms":443,"mutex_wait_us":314,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":18560,"update_count":2000}
I20260812 06:19:31.305158  2655 maintenance_manager.cc:419] P c2c876c0cbbb49a3982f118eaa59deae: Scheduling FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed): perf score=10.126437
I20260812 06:19:31.349887  2586 maintenance_manager.cc:643] P c2c876c0cbbb49a3982f118eaa59deae: FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed) complete. Timing: real 0.045s	user 0.016s	sys 0.019s Metrics: {"bytes_written":12307489,"delete_count":0,"lbm_write_time_us":15940,"lbm_writes_lt_1ms":303,"reinsert_count":0,"update_count":1500}
I20260812 06:19:31.350436  2655 maintenance_manager.cc:419] P c2c876c0cbbb49a3982f118eaa59deae: Scheduling FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed): perf score=2.188937
I20260812 06:19:31.361289  2586 maintenance_manager.cc:643] P c2c876c0cbbb49a3982f118eaa59deae: FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4068,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:31.362116  2655 maintenance_manager.cc:419] P c2c876c0cbbb49a3982f118eaa59deae: Scheduling FlushMRSOp(091f1f9162e841779c52a4a288c6f5ed): perf score=1.000000
I20260812 06:19:31.394644  2586 maintenance_manager.cc:643] P c2c876c0cbbb49a3982f118eaa59deae: FlushMRSOp(091f1f9162e841779c52a4a288c6f5ed) complete. Timing: real 0.032s	user 0.028s	sys 0.003s Metrics: {"bytes_written":1193509,"cfile_init":1,"dirs.queue_time_us":78,"dirs.run_cpu_time_us":210,"dirs.run_wall_time_us":1445,"drs_written":1,"lbm_read_time_us":63,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2033,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":29}
I20260812 06:19:31.395279  2655 maintenance_manager.cc:419] P c2c876c0cbbb49a3982f118eaa59deae: Scheduling LogGCOp(091f1f9162e841779c52a4a288c6f5ed): free 124710298 bytes of WAL
I20260812 06:19:31.395515  2586 log_reader.cc:385] T 091f1f9162e841779c52a4a288c6f5ed: removed 12 log segments from log reader
I20260812 06:19:31.395582  2586 log.cc:1079] T 091f1f9162e841779c52a4a288c6f5ed P c2c876c0cbbb49a3982f118eaa59deae: Deleting log segment in path: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515562549282-2253-0/minicluster-data/ts-0-root/wals/091f1f9162e841779c52a4a288c6f5ed/wal-000000014 (ops 66-70)
I20260812 06:19:31.395640  2586 log.cc:1079] T 091f1f9162e841779c52a4a288c6f5ed P c2c876c0cbbb49a3982f118eaa59deae: Deleting log segment in path: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515562549282-2253-0/minicluster-data/ts-0-root/wals/091f1f9162e841779c52a4a288c6f5ed/wal-000000015 (ops 71-75)
I20260812 06:19:31.395676  2586 log.cc:1079] T 091f1f9162e841779c52a4a288c6f5ed P c2c876c0cbbb49a3982f118eaa59deae: Deleting log segment in path: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515562549282-2253-0/minicluster-data/ts-0-root/wals/091f1f9162e841779c52a4a288c6f5ed/wal-000000016 (ops 76-80)
I20260812 06:19:31.395720  2586 log.cc:1079] T 091f1f9162e841779c52a4a288c6f5ed P c2c876c0cbbb49a3982f118eaa59deae: Deleting log segment in path: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515562549282-2253-0/minicluster-data/ts-0-root/wals/091f1f9162e841779c52a4a288c6f5ed/wal-000000017 (ops 81-85)
I20260812 06:19:31.395758  2586 log.cc:1079] T 091f1f9162e841779c52a4a288c6f5ed P c2c876c0cbbb49a3982f118eaa59deae: Deleting log segment in path: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515562549282-2253-0/minicluster-data/ts-0-root/wals/091f1f9162e841779c52a4a288c6f5ed/wal-000000018 (ops 86-90)
I20260812 06:19:31.395799  2586 log.cc:1079] T 091f1f9162e841779c52a4a288c6f5ed P c2c876c0cbbb49a3982f118eaa59deae: Deleting log segment in path: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515562549282-2253-0/minicluster-data/ts-0-root/wals/091f1f9162e841779c52a4a288c6f5ed/wal-000000019 (ops 91-95)
I20260812 06:19:31.395836  2586 log.cc:1079] T 091f1f9162e841779c52a4a288c6f5ed P c2c876c0cbbb49a3982f118eaa59deae: Deleting log segment in path: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515562549282-2253-0/minicluster-data/ts-0-root/wals/091f1f9162e841779c52a4a288c6f5ed/wal-000000020 (ops 96-100)
I20260812 06:19:31.395877  2586 log.cc:1079] T 091f1f9162e841779c52a4a288c6f5ed P c2c876c0cbbb49a3982f118eaa59deae: Deleting log segment in path: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515562549282-2253-0/minicluster-data/ts-0-root/wals/091f1f9162e841779c52a4a288c6f5ed/wal-000000021 (ops 101-105)
I20260812 06:19:31.395915  2586 log.cc:1079] T 091f1f9162e841779c52a4a288c6f5ed P c2c876c0cbbb49a3982f118eaa59deae: Deleting log segment in path: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515562549282-2253-0/minicluster-data/ts-0-root/wals/091f1f9162e841779c52a4a288c6f5ed/wal-000000022 (ops 106-110)
I20260812 06:19:31.395954  2586 log.cc:1079] T 091f1f9162e841779c52a4a288c6f5ed P c2c876c0cbbb49a3982f118eaa59deae: Deleting log segment in path: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515562549282-2253-0/minicluster-data/ts-0-root/wals/091f1f9162e841779c52a4a288c6f5ed/wal-000000023 (ops 111-115)
I20260812 06:19:31.396000  2586 log.cc:1079] T 091f1f9162e841779c52a4a288c6f5ed P c2c876c0cbbb49a3982f118eaa59deae: Deleting log segment in path: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515562549282-2253-0/minicluster-data/ts-0-root/wals/091f1f9162e841779c52a4a288c6f5ed/wal-000000024 (ops 116-120)
I20260812 06:19:31.396039  2586 log.cc:1079] T 091f1f9162e841779c52a4a288c6f5ed P c2c876c0cbbb49a3982f118eaa59deae: Deleting log segment in path: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515562549282-2253-0/minicluster-data/ts-0-root/wals/091f1f9162e841779c52a4a288c6f5ed/wal-000000025 (ops 121-125)
I20260812 06:19:31.423406  2586 maintenance_manager.cc:643] P c2c876c0cbbb49a3982f118eaa59deae: LogGCOp(091f1f9162e841779c52a4a288c6f5ed) complete. Timing: real 0.028s	user 0.000s	sys 0.025s Metrics: {}
I20260812 06:19:31.423838  2655 maintenance_manager.cc:419] P c2c876c0cbbb49a3982f118eaa59deae: Scheduling FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed): perf score=3.181125
I20260812 06:19:31.436254  2586 maintenance_manager.cc:643] P c2c876c0cbbb49a3982f118eaa59deae: FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed) complete. Timing: real 0.012s	user 0.007s	sys 0.004s Metrics: {"bytes_written":4471875,"delete_count":0,"lbm_write_time_us":4787,"lbm_writes_lt_1ms":112,"reinsert_count":0,"update_count":545}
I20260812 06:19:31.436736  2655 maintenance_manager.cc:419] P c2c876c0cbbb49a3982f118eaa59deae: Scheduling FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed): perf score=2.188937
I20260812 06:19:31.447886  2586 maintenance_manager.cc:643] P c2c876c0cbbb49a3982f118eaa59deae: FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":3733434,"delete_count":0,"lbm_write_time_us":4118,"lbm_writes_lt_1ms":94,"reinsert_count":0,"update_count":455}
I20260812 06:19:31.448437  2655 maintenance_manager.cc:419] P c2c876c0cbbb49a3982f118eaa59deae: Scheduling UndoDeltaBlockGCOp(091f1f9162e841779c52a4a288c6f5ed): 463 bytes on disk
I20260812 06:19:31.449038  2586 maintenance_manager.cc:643] P c2c876c0cbbb49a3982f118eaa59deae: UndoDeltaBlockGCOp(091f1f9162e841779c52a4a288c6f5ed) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":71,"lbm_reads_lt_1ms":4}
I20260812 06:19:31.449729  2655 maintenance_manager.cc:419] P c2c876c0cbbb49a3982f118eaa59deae: Scheduling MajorDeltaCompactionOp(091f1f9162e841779c52a4a288c6f5ed): perf score=1.000000
I20260812 06:19:31.616050  2586 maintenance_manager.cc:643] P c2c876c0cbbb49a3982f118eaa59deae: MajorDeltaCompactionOp(091f1f9162e841779c52a4a288c6f5ed) complete. Timing: real 0.166s	user 0.117s	sys 0.049s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877329,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":497,"lbm_read_time_us":11667,"lbm_reads_lt_1ms":674,"lbm_write_time_us":32445,"lbm_writes_lt_1ms":643,"mutex_wait_us":22,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":12800,"thread_start_us":78,"threads_started":1,"update_count":3000}
I20260812 06:19:31.616741  2655 maintenance_manager.cc:419] P c2c876c0cbbb49a3982f118eaa59deae: Scheduling FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed): perf score=14.095187
I20260812 06:19:31.666242  2586 maintenance_manager.cc:643] P c2c876c0cbbb49a3982f118eaa59deae: FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed) complete. Timing: real 0.049s	user 0.027s	sys 0.020s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":21474,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:31.666826  2655 maintenance_manager.cc:419] P c2c876c0cbbb49a3982f118eaa59deae: Scheduling FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed): perf score=2.188937
I20260812 06:19:31.680614  2586 maintenance_manager.cc:643] P c2c876c0cbbb49a3982f118eaa59deae: FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed) complete. Timing: real 0.014s	user 0.010s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5182,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:31.681294  2655 maintenance_manager.cc:419] P c2c876c0cbbb49a3982f118eaa59deae: Scheduling MajorDeltaCompactionOp(091f1f9162e841779c52a4a288c6f5ed): perf score=1.000000
I20260812 06:19:31.845293  2586 maintenance_manager.cc:643] P c2c876c0cbbb49a3982f118eaa59deae: MajorDeltaCompactionOp(091f1f9162e841779c52a4a288c6f5ed) complete. Timing: real 0.164s	user 0.120s	sys 0.032s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":1044,"lbm_read_time_us":8718,"lbm_reads_lt_1ms":564,"lbm_write_time_us":30045,"lbm_writes_lt_1ms":543,"mutex_wait_us":337,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":8448,"update_count":2500}
I20260812 06:19:31.845937  2655 maintenance_manager.cc:419] P c2c876c0cbbb49a3982f118eaa59deae: Scheduling FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed): perf score=14.095187
I20260812 06:19:31.904587  2586 maintenance_manager.cc:643] P c2c876c0cbbb49a3982f118eaa59deae: FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed) complete. Timing: real 0.058s	user 0.038s	sys 0.016s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":24914,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:31.905117  2655 maintenance_manager.cc:419] P c2c876c0cbbb49a3982f118eaa59deae: Scheduling MajorDeltaCompactionOp(091f1f9162e841779c52a4a288c6f5ed): perf score=1.000000
I20260812 06:19:32.053160  2586 maintenance_manager.cc:643] P c2c876c0cbbb49a3982f118eaa59deae: MajorDeltaCompactionOp(091f1f9162e841779c52a4a288c6f5ed) complete. Timing: real 0.148s	user 0.084s	sys 0.060s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672157,"cfile_init":8,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":521,"lbm_read_time_us":9587,"lbm_reads_lt_1ms":463,"lbm_write_time_us":25291,"lbm_writes_lt_1ms":443,"mutex_wait_us":317,"peak_mem_usage":50689328,"reinsert_count":0,"spinlock_wait_cycles":7424,"update_count":2000}
I20260812 06:19:32.053799  2655 maintenance_manager.cc:419] P c2c876c0cbbb49a3982f118eaa59deae: Scheduling FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed): perf score=14.095187
I20260812 06:19:32.101886  2586 maintenance_manager.cc:643] P c2c876c0cbbb49a3982f118eaa59deae: FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed) complete. Timing: real 0.048s	user 0.027s	sys 0.020s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":21446,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:32.102361  2655 maintenance_manager.cc:419] P c2c876c0cbbb49a3982f118eaa59deae: Scheduling FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed): perf score=2.188937
I20260812 06:19:32.129613  2586 maintenance_manager.cc:643] P c2c876c0cbbb49a3982f118eaa59deae: FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed) complete. Timing: real 0.027s	user 0.011s	sys 0.011s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":6046,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:32.130633  2655 maintenance_manager.cc:419] P c2c876c0cbbb49a3982f118eaa59deae: Scheduling FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed): perf score=1.000000
I20260812 06:19:32.140072  2586 maintenance_manager.cc:643] P c2c876c0cbbb49a3982f118eaa59deae: FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed) complete. Timing: real 0.009s	user 0.000s	sys 0.003s Metrics: {"bytes_written":1230906,"delete_count":0,"lbm_write_time_us":1303,"lbm_writes_lt_1ms":33,"reinsert_count":0,"update_count":150}
I20260812 06:19:32.140626  2655 maintenance_manager.cc:419] P c2c876c0cbbb49a3982f118eaa59deae: Scheduling FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed): perf score=1.196750
I20260812 06:19:32.149195  2586 maintenance_manager.cc:643] P c2c876c0cbbb49a3982f118eaa59deae: FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed) complete. Timing: real 0.008s	user 0.002s	sys 0.006s Metrics: {"bytes_written":2871905,"delete_count":0,"lbm_write_time_us":3112,"lbm_writes_lt_1ms":73,"reinsert_count":0,"update_count":350}
I20260812 06:19:32.149678  2655 maintenance_manager.cc:419] P c2c876c0cbbb49a3982f118eaa59deae: Scheduling MajorDeltaCompactionOp(091f1f9162e841779c52a4a288c6f5ed): perf score=1.000000
I20260812 06:19:32.348315  2586 maintenance_manager.cc:643] P c2c876c0cbbb49a3982f118eaa59deae: MajorDeltaCompactionOp(091f1f9162e841779c52a4a288c6f5ed) complete. Timing: real 0.198s	user 0.100s	sys 0.098s Metrics: {"cfile_cache_miss":634,"cfile_cache_miss_bytes":28877245,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"dirs.queue_time_us":295,"lbm_read_time_us":14610,"lbm_reads_lt_1ms":674,"lbm_write_time_us":33272,"lbm_writes_lt_1ms":643,"mutex_wait_us":50,"peak_mem_usage":75542472,"reinsert_count":0,"spinlock_wait_cycles":768,"update_count":3000}
I20260812 06:19:32.349054  2655 maintenance_manager.cc:419] P c2c876c0cbbb49a3982f118eaa59deae: Scheduling FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed): perf score=14.095187
I20260812 06:19:32.411826  2586 maintenance_manager.cc:643] P c2c876c0cbbb49a3982f118eaa59deae: FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed) complete. Timing: real 0.063s	user 0.037s	sys 0.022s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":22890,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:32.412541  2655 maintenance_manager.cc:419] P c2c876c0cbbb49a3982f118eaa59deae: Scheduling FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed): perf score=2.188937
I20260812 06:19:32.424695  2586 maintenance_manager.cc:643] P c2c876c0cbbb49a3982f118eaa59deae: FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed) complete. Timing: real 0.012s	user 0.007s	sys 0.005s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4875,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:32.425179  2655 maintenance_manager.cc:419] P c2c876c0cbbb49a3982f118eaa59deae: Scheduling MajorDeltaCompactionOp(091f1f9162e841779c52a4a288c6f5ed): perf score=1.000000
I20260812 06:19:32.599152  2586 maintenance_manager.cc:643] P c2c876c0cbbb49a3982f118eaa59deae: MajorDeltaCompactionOp(091f1f9162e841779c52a4a288c6f5ed) complete. Timing: real 0.174s	user 0.095s	sys 0.069s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":10,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":651,"lbm_read_time_us":11967,"lbm_reads_lt_1ms":572,"lbm_write_time_us":27406,"lbm_writes_lt_1ms":543,"mutex_wait_us":51,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":9856,"update_count":2500}
I20260812 06:19:32.599893  2655 maintenance_manager.cc:419] P c2c876c0cbbb49a3982f118eaa59deae: Scheduling FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed): perf score=14.095187
I20260812 06:19:32.660885  2586 maintenance_manager.cc:643] P c2c876c0cbbb49a3982f118eaa59deae: FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed) complete. Timing: real 0.061s	user 0.021s	sys 0.038s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":20548,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:32.661521  2655 maintenance_manager.cc:419] P c2c876c0cbbb49a3982f118eaa59deae: Scheduling FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed): perf score=2.188937
I20260812 06:19:32.674907  2586 maintenance_manager.cc:643] P c2c876c0cbbb49a3982f118eaa59deae: FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed) complete. Timing: real 0.013s	user 0.010s	sys 0.001s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4786,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:32.675539  2655 maintenance_manager.cc:419] P c2c876c0cbbb49a3982f118eaa59deae: Scheduling MajorDeltaCompactionOp(091f1f9162e841779c52a4a288c6f5ed): perf score=1.000000
I20260812 06:19:32.853843  2586 maintenance_manager.cc:643] P c2c876c0cbbb49a3982f118eaa59deae: MajorDeltaCompactionOp(091f1f9162e841779c52a4a288c6f5ed) complete. Timing: real 0.178s	user 0.130s	sys 0.046s Metrics: {"cfile_cache_miss":532,"cfile_cache_miss_bytes":24774688,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":2,"delta_iterators_relevant":2,"dirs.queue_time_us":188,"lbm_read_time_us":11551,"lbm_reads_lt_1ms":568,"lbm_write_time_us":27225,"lbm_writes_lt_1ms":543,"mutex_wait_us":28,"peak_mem_usage":63115900,"reinsert_count":0,"spinlock_wait_cycles":12288,"update_count":2500}
I20260812 06:19:32.854568  2655 maintenance_manager.cc:419] P c2c876c0cbbb49a3982f118eaa59deae: Scheduling FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed): perf score=14.095187
I20260812 06:19:32.900873  2586 maintenance_manager.cc:643] P c2c876c0cbbb49a3982f118eaa59deae: FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed) complete. Timing: real 0.046s	user 0.022s	sys 0.024s Metrics: {"bytes_written":16409902,"delete_count":0,"lbm_write_time_us":20285,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:32.901394  2655 maintenance_manager.cc:419] P c2c876c0cbbb49a3982f118eaa59deae: Scheduling FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed): perf score=2.188937
I20260812 06:19:32.912684  2586 maintenance_manager.cc:643] P c2c876c0cbbb49a3982f118eaa59deae: FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed) complete. Timing: real 0.011s	user 0.006s	sys 0.004s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":4082,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:32.913156  2655 maintenance_manager.cc:419] P c2c876c0cbbb49a3982f118eaa59deae: Scheduling FlushMRSOp(091f1f9162e841779c52a4a288c6f5ed): perf score=1.000000
I20260812 06:19:32.949999  2586 maintenance_manager.cc:643] P c2c876c0cbbb49a3982f118eaa59deae: FlushMRSOp(091f1f9162e841779c52a4a288c6f5ed) complete. Timing: real 0.037s	user 0.033s	sys 0.000s Metrics: {"bytes_written":1316417,"cfile_init":1,"dirs.queue_time_us":75,"dirs.run_cpu_time_us":199,"dirs.run_wall_time_us":1254,"drs_written":1,"lbm_read_time_us":80,"lbm_reads_lt_1ms":4,"lbm_write_time_us":2463,"lbm_writes_lt_1ms":39,"peak_mem_usage":0,"rows_written":32}
I20260812 06:19:32.950668  2655 maintenance_manager.cc:419] P c2c876c0cbbb49a3982f118eaa59deae: Scheduling LogGCOp(091f1f9162e841779c52a4a288c6f5ed): free 132571588 bytes of WAL
I20260812 06:19:32.950896  2586 log_reader.cc:385] T 091f1f9162e841779c52a4a288c6f5ed: removed 13 log segments from log reader
I20260812 06:19:32.950970  2586 log.cc:1079] T 091f1f9162e841779c52a4a288c6f5ed P c2c876c0cbbb49a3982f118eaa59deae: Deleting log segment in path: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515562549282-2253-0/minicluster-data/ts-0-root/wals/091f1f9162e841779c52a4a288c6f5ed/wal-000000026 (ops 126-130)
I20260812 06:19:32.951027  2586 log.cc:1079] T 091f1f9162e841779c52a4a288c6f5ed P c2c876c0cbbb49a3982f118eaa59deae: Deleting log segment in path: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515562549282-2253-0/minicluster-data/ts-0-root/wals/091f1f9162e841779c52a4a288c6f5ed/wal-000000027 (ops 131-135)
I20260812 06:19:32.951087  2586 log.cc:1079] T 091f1f9162e841779c52a4a288c6f5ed P c2c876c0cbbb49a3982f118eaa59deae: Deleting log segment in path: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515562549282-2253-0/minicluster-data/ts-0-root/wals/091f1f9162e841779c52a4a288c6f5ed/wal-000000028 (ops 136-140)
I20260812 06:19:32.951130  2586 log.cc:1079] T 091f1f9162e841779c52a4a288c6f5ed P c2c876c0cbbb49a3982f118eaa59deae: Deleting log segment in path: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515562549282-2253-0/minicluster-data/ts-0-root/wals/091f1f9162e841779c52a4a288c6f5ed/wal-000000029 (ops 141-145)
I20260812 06:19:32.951171  2586 log.cc:1079] T 091f1f9162e841779c52a4a288c6f5ed P c2c876c0cbbb49a3982f118eaa59deae: Deleting log segment in path: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515562549282-2253-0/minicluster-data/ts-0-root/wals/091f1f9162e841779c52a4a288c6f5ed/wal-000000030 (ops 146-150)
I20260812 06:19:32.951212  2586 log.cc:1079] T 091f1f9162e841779c52a4a288c6f5ed P c2c876c0cbbb49a3982f118eaa59deae: Deleting log segment in path: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515562549282-2253-0/minicluster-data/ts-0-root/wals/091f1f9162e841779c52a4a288c6f5ed/wal-000000031 (ops 151-155)
I20260812 06:19:32.951253  2586 log.cc:1079] T 091f1f9162e841779c52a4a288c6f5ed P c2c876c0cbbb49a3982f118eaa59deae: Deleting log segment in path: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515562549282-2253-0/minicluster-data/ts-0-root/wals/091f1f9162e841779c52a4a288c6f5ed/wal-000000032 (ops 156-160)
I20260812 06:19:32.951293  2586 log.cc:1079] T 091f1f9162e841779c52a4a288c6f5ed P c2c876c0cbbb49a3982f118eaa59deae: Deleting log segment in path: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515562549282-2253-0/minicluster-data/ts-0-root/wals/091f1f9162e841779c52a4a288c6f5ed/wal-000000033 (ops 161-164)
I20260812 06:19:32.951331  2586 log.cc:1079] T 091f1f9162e841779c52a4a288c6f5ed P c2c876c0cbbb49a3982f118eaa59deae: Deleting log segment in path: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515562549282-2253-0/minicluster-data/ts-0-root/wals/091f1f9162e841779c52a4a288c6f5ed/wal-000000034 (ops 165-169)
I20260812 06:19:32.951371  2586 log.cc:1079] T 091f1f9162e841779c52a4a288c6f5ed P c2c876c0cbbb49a3982f118eaa59deae: Deleting log segment in path: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515562549282-2253-0/minicluster-data/ts-0-root/wals/091f1f9162e841779c52a4a288c6f5ed/wal-000000035 (ops 170-174)
I20260812 06:19:32.951411  2586 log.cc:1079] T 091f1f9162e841779c52a4a288c6f5ed P c2c876c0cbbb49a3982f118eaa59deae: Deleting log segment in path: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515562549282-2253-0/minicluster-data/ts-0-root/wals/091f1f9162e841779c52a4a288c6f5ed/wal-000000036 (ops 175-179)
I20260812 06:19:32.951447  2586 log.cc:1079] T 091f1f9162e841779c52a4a288c6f5ed P c2c876c0cbbb49a3982f118eaa59deae: Deleting log segment in path: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515562549282-2253-0/minicluster-data/ts-0-root/wals/091f1f9162e841779c52a4a288c6f5ed/wal-000000037 (ops 180-184)
I20260812 06:19:32.951489  2586 log.cc:1079] T 091f1f9162e841779c52a4a288c6f5ed P c2c876c0cbbb49a3982f118eaa59deae: Deleting log segment in path: /tmp/dist-test-taskMzX1dO/test-tmp/heavy-update-compaction-itest.0.EvictionPolicyTypes_HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction_1.1786515562549282-2253-0/minicluster-data/ts-0-root/wals/091f1f9162e841779c52a4a288c6f5ed/wal-000000038 (ops 185-188)
I20260812 06:19:32.981081  2586 maintenance_manager.cc:643] P c2c876c0cbbb49a3982f118eaa59deae: LogGCOp(091f1f9162e841779c52a4a288c6f5ed) complete. Timing: real 0.030s	user 0.000s	sys 0.030s Metrics: {}
I20260812 06:19:32.981519  2655 maintenance_manager.cc:419] P c2c876c0cbbb49a3982f118eaa59deae: Scheduling UndoDeltaBlockGCOp(091f1f9162e841779c52a4a288c6f5ed): 492 bytes on disk
I20260812 06:19:32.981992  2586 maintenance_manager.cc:643] P c2c876c0cbbb49a3982f118eaa59deae: UndoDeltaBlockGCOp(091f1f9162e841779c52a4a288c6f5ed) complete. Timing: real 0.000s	user 0.000s	sys 0.000s Metrics: {"cfile_init":1,"lbm_read_time_us":61,"lbm_reads_lt_1ms":4}
I20260812 06:19:32.982702  2655 maintenance_manager.cc:419] P c2c876c0cbbb49a3982f118eaa59deae: Scheduling FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed): perf score=2.188937
I20260812 06:19:33.002609  2586 maintenance_manager.cc:643] P c2c876c0cbbb49a3982f118eaa59deae: FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed) complete. Timing: real 0.020s	user 0.003s	sys 0.007s Metrics: {"bytes_written":4102658,"delete_count":0,"lbm_write_time_us":4605,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:33.003154  2655 maintenance_manager.cc:419] P c2c876c0cbbb49a3982f118eaa59deae: Scheduling FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed): perf score=2.188937
I20260812 06:19:33.018302  2586 maintenance_manager.cc:643] P c2c876c0cbbb49a3982f118eaa59deae: FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed) complete. Timing: real 0.015s	user 0.005s	sys 0.008s Metrics: {"bytes_written":4102659,"delete_count":0,"lbm_write_time_us":5862,"lbm_writes_lt_1ms":103,"reinsert_count":0,"update_count":500}
I20260812 06:19:33.019001  2655 maintenance_manager.cc:419] P c2c876c0cbbb49a3982f118eaa59deae: Scheduling MajorDeltaCompactionOp(091f1f9162e841779c52a4a288c6f5ed): perf score=1.000000
I20260812 06:19:33.207343  2253 heavy-update-compaction-itest.cc:229] Time spent updating: real 4.974s	user 1.814s	sys 0.184s
I20260812 06:19:33.253515  2586 maintenance_manager.cc:643] P c2c876c0cbbb49a3982f118eaa59deae: MajorDeltaCompactionOp(091f1f9162e841779c52a4a288c6f5ed) complete. Timing: real 0.234s	user 0.147s	sys 0.086s Metrics: {"cfile_cache_miss":734,"cfile_cache_miss_bytes":32979750,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":4,"delta_iterators_relevant":4,"lbm_read_time_us":13765,"lbm_reads_lt_1ms":770,"lbm_write_time_us":41539,"lbm_writes_lt_1ms":743,"peak_mem_usage":87969044,"reinsert_count":0,"spinlock_wait_cycles":1664,"update_count":3500}
I20260812 06:19:33.254160  2655 maintenance_manager.cc:419] P c2c876c0cbbb49a3982f118eaa59deae: Scheduling FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed): perf score=14.095187
I20260812 06:19:33.287328  2586 maintenance_manager.cc:643] P c2c876c0cbbb49a3982f118eaa59deae: FlushDeltaMemStoresOp(091f1f9162e841779c52a4a288c6f5ed) complete. Timing: real 0.033s	user 0.020s	sys 0.012s Metrics: {"bytes_written":16409901,"delete_count":0,"lbm_write_time_us":16404,"lbm_writes_lt_1ms":403,"reinsert_count":0,"update_count":2000}
I20260812 06:19:33.287889  2655 maintenance_manager.cc:419] P c2c876c0cbbb49a3982f118eaa59deae: Scheduling MajorDeltaCompactionOp(091f1f9162e841779c52a4a288c6f5ed): perf score=1.000000
I20260812 06:19:33.314134  2253 heavy-update-compaction-itest.cc:265] Time spent scanning: real 0.106s	user 0.001s	sys 0.000s
I20260812 06:19:33.314642  2253 tablet_server.cc:179] TabletServer@127.2.51.65:0 shutting down...
I20260812 06:19:33.413476  2586 maintenance_manager.cc:643] P c2c876c0cbbb49a3982f118eaa59deae: MajorDeltaCompactionOp(091f1f9162e841779c52a4a288c6f5ed) complete. Timing: real 0.125s	user 0.083s	sys 0.041s Metrics: {"cfile_cache_miss":431,"cfile_cache_miss_bytes":20672157,"cfile_init":9,"delete_count":0,"delta_blocks_compacted":1,"delta_iterators_relevant":1,"dirs.queue_time_us":485,"lbm_read_time_us":10071,"lbm_reads_lt_1ms":467,"lbm_write_time_us":24628,"lbm_writes_1-10_ms":1,"lbm_writes_lt_1ms":442,"mutex_wait_us":112,"peak_mem_usage":50689328,"reinsert_count":0,"update_count":2000}
I20260812 06:19:33.414376  2253 ts_tablet_manager.cc:1507] Shutting down tablet manager...
I20260812 06:19:33.414685  2253 tablet_replica.cc:333] T 091f1f9162e841779c52a4a288c6f5ed P c2c876c0cbbb49a3982f118eaa59deae: stopping tablet replica
I20260812 06:19:33.414850  2253 raft_consensus.cc:2243] T 091f1f9162e841779c52a4a288c6f5ed P c2c876c0cbbb49a3982f118eaa59deae [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:33.415113  2253 raft_consensus.cc:2272] T 091f1f9162e841779c52a4a288c6f5ed P c2c876c0cbbb49a3982f118eaa59deae [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:33.419560  2253 tablet_server.cc:196] TabletServer@127.2.51.65:0 shutdown complete.
I20260812 06:19:33.454175  2253 master.cc:562] Master@127.2.51.126:35711 shutting down...
I20260812 06:19:33.459728  2253 raft_consensus.cc:2243] T 00000000000000000000000000000000 P 601892bd52a44d2bb8903caedeca21c8 [term 1 LEADER]: Raft consensus shutting down.
I20260812 06:19:33.459941  2253 raft_consensus.cc:2272] T 00000000000000000000000000000000 P 601892bd52a44d2bb8903caedeca21c8 [term 1 FOLLOWER]: Raft consensus is shut down!
I20260812 06:19:33.460042  2253 tablet_replica.cc:333] T 00000000000000000000000000000000 P 601892bd52a44d2bb8903caedeca21c8: stopping tablet replica
I20260812 06:19:33.472618  2253 master.cc:584] Master@127.2.51.126:35711 shutdown complete.
[       OK ] EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy.TestHeavyUpdateCompaction/1 (5536 ms)
[----------] 2 tests from EvictionPolicyTypes/HeavyUpdateCompactionITestWithEvictionPolicy (11002 ms total)

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